[==========] 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:11.197278 29607 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.233.254:37713
I20260812 06:19:11.198390 29607 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:11.199096 29607 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.205750 29614 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:11.205773 29613 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:11.205955 29607 server_base.cc:1061] running on GCE node
W20260812 06:19:11.206065 29616 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:11.206801 29607 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.206934 29607 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:11.207039 29607 hybrid_clock.cc:648] HybridClock initialized: now 1786515551207034 us; error 0 us; skew 500 ppm
I20260812 06:19:11.209055 29607 webserver.cc:533] Webserver started at http://127.28.233.254:40639/ using document root <none> and password file <none>
I20260812 06:19:11.209687 29607 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.209785 29607 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.210045 29607 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.211884 29607 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/master-0-root/instance:
uuid: "7506d5b00b4745ea92978c0bf3c31168"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-5l3k"
I20260812 06:19:11.215806 29607 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:11.218171 29621 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:11.219388 29607 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:11.219535 29607 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/master-0-root
uuid: "7506d5b00b4745ea92978c0bf3c31168"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-5l3k"
I20260812 06:19:11.219652 29607 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-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:11.241242 29607 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.241983 29607 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:11.242192 29607 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.250427 29607 rpc_server.cc:307] RPC server started. Bound to: 127.28.233.254:37713
I20260812 06:19:11.250554 29679 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.233.254:37713 every 8 connection(s)
I20260812 06:19:11.252823 29680 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:11.258414 29680 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: Bootstrap starting.
I20260812 06:19:11.260923 29680 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.261912 29680 log.cc:826] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:11.263937 29680 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: No bootstrap required, opened a new log
I20260812 06:19:11.267099 29680 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER }
I20260812 06:19:11.267313 29680 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.267409 29680 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7506d5b00b4745ea92978c0bf3c31168, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.268114 29680 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [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: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER }
I20260812 06:19:11.268268 29680 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.268383 29680 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.268510 29680 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.269446 29680 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER }
I20260812 06:19:11.269935 29680 leader_election.cc:304] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [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: 7506d5b00b4745ea92978c0bf3c31168; no voters: 
I20260812 06:19:11.270331 29680 leader_election.cc:290] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.270596 29683 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.270888 29683 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 1 LEADER]: Becoming Leader. State: Replica: 7506d5b00b4745ea92978c0bf3c31168, State: Running, Role: LEADER
I20260812 06:19:11.271339 29683 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [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: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER }
I20260812 06:19:11.271459 29680 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:11.273316 29685 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7506d5b00b4745ea92978c0bf3c31168. Latest consensus state: current_term: 1 leader_uuid: "7506d5b00b4745ea92978c0bf3c31168" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER } }
I20260812 06:19:11.273356 29684 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7506d5b00b4745ea92978c0bf3c31168" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7506d5b00b4745ea92978c0bf3c31168" member_type: VOTER } }
I20260812 06:19:11.273463 29685 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.273464 29684 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.273882 29696 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:11.274120 29607 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:11.276866 29696 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:11.282851 29696 catalog_manager.cc:1383] Generated new cluster ID: 91e1ef73094c44c6952605787de5ca02
I20260812 06:19:11.282956 29696 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:11.297575 29696 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:11.298679 29696 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:11.310839 29696 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: Generated new TSK 0
I20260812 06:19:11.311659 29696 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:11.339564 29607 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.342808 29706 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:11.342801 29708 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:11.342960 29705 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:11.343195 29607 server_base.cc:1061] running on GCE node
I20260812 06:19:11.343389 29607 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.343446 29607 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:11.343472 29607 hybrid_clock.cc:648] HybridClock initialized: now 1786515551343471 us; error 0 us; skew 500 ppm
I20260812 06:19:11.344506 29607 webserver.cc:533] Webserver started at http://127.28.233.193:44377/ using document root <none> and password file <none>
I20260812 06:19:11.344691 29607 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.344770 29607 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.344858 29607 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.345327 29607 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/instance:
uuid: "775c3f5202ef4feea3f0e1314a4ab8ba"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-5l3k"
I20260812 06:19:11.347029 29607 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:11.348112 29714 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:11.348376 29607 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.348449 29607 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root
uuid: "775c3f5202ef4feea3f0e1314a4ab8ba"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-5l3k"
I20260812 06:19:11.348548 29607 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-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:11.353973 29607 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.354434 29607 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.354960 29607 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:11.355815 29607 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:11.355867 29607 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.355940 29607 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:11.355980 29607 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.363142 29607 rpc_server.cc:307] RPC server started. Bound to: 127.28.233.193:36983
I20260812 06:19:11.363158 29786 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.233.193:36983 every 8 connection(s)
I20260812 06:19:11.379756 29787 heartbeater.cc:344] Connected to a master server at 127.28.233.254:37713
I20260812 06:19:11.380053 29787 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:11.380600 29787 heartbeater.cc:507] Master 127.28.233.254:37713 requested a full tablet report, sending...
I20260812 06:19:11.382022 29639 ts_manager.cc:194] Registered new tserver with Master: 775c3f5202ef4feea3f0e1314a4ab8ba (127.28.233.193:36983)
I20260812 06:19:11.382915 29607 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019049894s
I20260812 06:19:11.383289 29639 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35176
I20260812 06:19:11.393082 29639 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35182:
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:11.408566 29737 tablet_service.cc:1511] Processing CreateTablet for tablet 035b3060535147c7ae90c0662ebfdd7f (DEFAULT_TABLE table=heavy-update-compaction-test [id=02d9f3c72cd3410bb5189881fc3e05cf]), partition=
I20260812 06:19:11.409113 29737 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 035b3060535147c7ae90c0662ebfdd7f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.422001 29802 tablet_bootstrap.cc:492] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Bootstrap starting.
I20260812 06:19:11.423295 29802 tablet_bootstrap.cc:654] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.425271 29802 tablet_bootstrap.cc:492] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: No bootstrap required, opened a new log
I20260812 06:19:11.425431 29802 ts_tablet_manager.cc:1403] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:19:11.425938 29802 raft_consensus.cc:359] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "775c3f5202ef4feea3f0e1314a4ab8ba" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 36983 } }
I20260812 06:19:11.426074 29802 raft_consensus.cc:385] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.426179 29802 raft_consensus.cc:740] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 775c3f5202ef4feea3f0e1314a4ab8ba, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.426379 29802 consensus_queue.cc:260] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [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: "775c3f5202ef4feea3f0e1314a4ab8ba" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 36983 } }
I20260812 06:19:11.426515 29802 raft_consensus.cc:399] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.426568 29802 raft_consensus.cc:493] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.426623 29802 raft_consensus.cc:3060] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.427556 29802 raft_consensus.cc:515] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "775c3f5202ef4feea3f0e1314a4ab8ba" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 36983 } }
I20260812 06:19:11.427737 29802 leader_election.cc:304] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [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: 775c3f5202ef4feea3f0e1314a4ab8ba; no voters: 
I20260812 06:19:11.428042 29802 leader_election.cc:290] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.428151 29804 raft_consensus.cc:2804] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.428401 29804 raft_consensus.cc:697] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 1 LEADER]: Becoming Leader. State: Replica: 775c3f5202ef4feea3f0e1314a4ab8ba, State: Running, Role: LEADER
I20260812 06:19:11.428527 29802 ts_tablet_manager.cc:1434] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:11.428617 29804 consensus_queue.cc:237] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [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: "775c3f5202ef4feea3f0e1314a4ab8ba" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 36983 } }
I20260812 06:19:11.429023 29787 heartbeater.cc:499] Master 127.28.233.254:37713 was elected leader, sending a full tablet report...
I20260812 06:19:11.432093 29639 catalog_manager.cc:5719] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba reported cstate change: term changed from 0 to 1, leader changed from <none> to 775c3f5202ef4feea3f0e1314a4ab8ba (127.28.233.193). New cstate: current_term: 1 leader_uuid: "775c3f5202ef4feea3f0e1314a4ab8ba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "775c3f5202ef4feea3f0e1314a4ab8ba" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 36983 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:11.509408 29607 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.071s	user 0.014s	sys 0.007s
I20260812 06:19:11.614317 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f): perf score=15.086190
I20260812 06:19:11.770516 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.156s	user 0.123s	sys 0.028s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":205,"delete_count":0,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":973,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35098,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":137,"threads_started":1,"update_count":1050}
I20260812 06:19:11.772025 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling LogGCOp(035b3060535147c7ae90c0662ebfdd7f): free 20290830 bytes of WAL
I20260812 06:19:11.772646 29720 log_reader.cc:385] T 035b3060535147c7ae90c0662ebfdd7f: removed 2 log segments from log reader
I20260812 06:19:11.772756 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000001 (ops 1-6)
I20260812 06:19:11.772866 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000002 (ops 7-10)
I20260812 06:19:11.778822 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: LogGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:11.779314 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f): 12308959 bytes on disk
I20260812 06:19:11.780066 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f) 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:11.780637 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:11.808568 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.028s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5412,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.809075 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:11.824133 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.824672 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:11.974033 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.149s	user 0.094s	sys 0.048s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631422,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":991,"lbm_read_time_us":10068,"lbm_reads_lt_1ms":469,"lbm_write_time_us":25304,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"thread_start_us":337,"threads_started":5,"update_count":2000}
I20260812 06:19:11.974738 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:12.020506 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.046s	user 0.014s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15243,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.020970 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:12.032452 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.033078 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:12.163407 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.130s	user 0.119s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":9194,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25258,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":2000}
I20260812 06:19:12.164069 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:12.212757 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.049s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16027,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.213339 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:12.224293 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.224828 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:12.367389 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.142s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":10731,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23279,"lbm_writes_lt_1ms":443,"mutex_wait_us":327,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":52480,"update_count":2000}
I20260812 06:19:12.367980 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:12.417363 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.049s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17303,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.417898 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:12.429545 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.430217 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:12.566284 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.136s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":916,"lbm_read_time_us":9547,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25673,"lbm_writes_lt_1ms":443,"mutex_wait_us":347,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":57088,"update_count":2000}
I20260812 06:19:12.567118 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:12.612078 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.045s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20186,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.612771 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:12.628729 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.629261 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:12.750313 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":758,"lbm_read_time_us":7513,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24800,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:19:12.751222 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:12.785949 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14486,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.786737 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:12.802838 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6186,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.803483 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:12.949334 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.146s	user 0.107s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":10474,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30615,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:19:12.950125 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:12.987577 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.037s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12722,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.990339 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.004314 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5323,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.004848 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:13.031049 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.026s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1505,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:13.032006 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling LogGCOp(035b3060535147c7ae90c0662ebfdd7f): free 108535389 bytes of WAL
I20260812 06:19:13.032260 29720 log_reader.cc:385] T 035b3060535147c7ae90c0662ebfdd7f: removed 11 log segments from log reader
I20260812 06:19:13.032305 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000003 (ops 11-15)
I20260812 06:19:13.032336 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000004 (ops 16-20)
I20260812 06:19:13.032403 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000005 (ops 21-24)
I20260812 06:19:13.032446 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000006 (ops 25-29)
I20260812 06:19:13.032485 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000007 (ops 30-34)
I20260812 06:19:13.032541 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000008 (ops 35-39)
I20260812 06:19:13.032578 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000009 (ops 40-44)
I20260812 06:19:13.032616 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000010 (ops 45-49)
I20260812 06:19:13.032655 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000011 (ops 50-54)
I20260812 06:19:13.032692 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000012 (ops 55-58)
I20260812 06:19:13.032734 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000013 (ops 59-63)
I20260812 06:19:13.057415 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: LogGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.025s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:19:13.057878 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f): 462 bytes on disk
I20260812 06:19:13.058341 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.058835 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=3.181125
I20260812 06:19:13.070817 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4234,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:13.071302 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.081450 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.081956 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:13.279898 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.198s	user 0.122s	sys 0.075s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836352,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1017,"lbm_read_time_us":13414,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32542,"lbm_writes_lt_1ms":643,"mutex_wait_us":146,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15232,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:13.280614 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:13.334240 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.053s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26137,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.334834 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.346591 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.349838 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:13.512689 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.163s	user 0.095s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":11619,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28410,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":228224,"update_count":2500}
I20260812 06:19:13.513458 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:13.573350 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.060s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19088,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.573992 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.584725 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.585202 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:13.763758 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.178s	user 0.130s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1096,"lbm_read_time_us":12537,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32164,"lbm_writes_lt_1ms":543,"mutex_wait_us":382,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2500}
I20260812 06:19:13.764432 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:13.815706 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.051s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19002,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.816242 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.835075 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.019s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.835640 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:13.849633 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5230,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.850200 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:14.031795 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.181s	user 0.107s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":516,"lbm_read_time_us":12823,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31373,"lbm_writes_lt_1ms":543,"mutex_wait_us":99,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:14.032549 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:14.072786 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.040s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17217,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.073693 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.087560 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4797,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.088184 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:14.243717 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.155s	user 0.100s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":7792,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24433,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.244330 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:14.281652 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.037s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16839,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.282284 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.303937 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:14.304512 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.314726 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3723,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:14.315330 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:14.475502 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.160s	user 0.116s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733838,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":415,"lbm_read_time_us":9861,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31419,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:14.476541 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:14.532272 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.056s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":27190,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.532840 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.547232 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.547766 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:14.577214 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.029s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1717,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:14.577939 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling LogGCOp(035b3060535147c7ae90c0662ebfdd7f): free 132571369 bytes of WAL
I20260812 06:19:14.578166 29720 log_reader.cc:385] T 035b3060535147c7ae90c0662ebfdd7f: removed 13 log segments from log reader
I20260812 06:19:14.578228 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000014 (ops 64-68)
I20260812 06:19:14.578281 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000015 (ops 69-72)
I20260812 06:19:14.578337 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000016 (ops 73-77)
I20260812 06:19:14.578377 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000017 (ops 78-82)
I20260812 06:19:14.578413 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000018 (ops 83-87)
I20260812 06:19:14.578449 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000019 (ops 88-92)
I20260812 06:19:14.578511 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000020 (ops 93-97)
I20260812 06:19:14.578549 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000021 (ops 98-102)
I20260812 06:19:14.578586 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000022 (ops 103-107)
I20260812 06:19:14.578624 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000023 (ops 108-112)
I20260812 06:19:14.578660 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000024 (ops 113-117)
I20260812 06:19:14.578696 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000025 (ops 118-122)
I20260812 06:19:14.578732 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000026 (ops 123-126)
I20260812 06:19:14.609359 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: LogGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:14.609901 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=3.181125
I20260812 06:19:14.625840 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6307,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:14.626329 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.640017 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5137,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.640633 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:14.829715 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.189s	user 0.152s	sys 0.036s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":908,"lbm_read_time_us":13067,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39799,"lbm_writes_lt_1ms":743,"mutex_wait_us":382,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:14.830642 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f): 473 bytes on disk
I20260812 06:19:14.831295 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.832261 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:14.881790 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.049s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.882444 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:14.896622 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.897089 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.060520 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.163s	user 0.125s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":10218,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31435,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:15.061218 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:15.114270 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.053s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24935,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2000}
I20260812 06:19:15.114921 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:15.130638 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.131345 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.309952 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.178s	user 0.130s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1059,"lbm_read_time_us":11171,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29165,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58752,"update_count":2500}
I20260812 06:19:15.310787 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:15.357757 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.047s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19994,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.358595 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.520015 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.161s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":394,"lbm_read_time_us":8946,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28991,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:15.520916 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=11.118625
I20260812 06:19:15.562376 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.041s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18146,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:15.562983 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:15.575953 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.576547 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.710565 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.134s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":731,"lbm_read_time_us":9211,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26481,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:19:15.711333 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:15.748081 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16266,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.748634 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:15.759918 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4364,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.760402 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.892952 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.132s	user 0.115s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":8809,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23630,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:15.893720 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:15.929136 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.034s	user 0.021s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15747,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.929708 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:15.940716 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.941506 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:15.974553 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushMRSOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.033s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1586,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2200,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:15.975209 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling LogGCOp(035b3060535147c7ae90c0662ebfdd7f): free 108988735 bytes of WAL
I20260812 06:19:15.975433 29720 log_reader.cc:385] T 035b3060535147c7ae90c0662ebfdd7f: removed 11 log segments from log reader
I20260812 06:19:15.975476 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000027 (ops 127-131)
I20260812 06:19:15.975503 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000028 (ops 132-136)
I20260812 06:19:15.975548 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000029 (ops 137-140)
I20260812 06:19:15.975591 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000030 (ops 141-145)
I20260812 06:19:15.975626 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000031 (ops 146-150)
I20260812 06:19:15.975668 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000032 (ops 151-155)
I20260812 06:19:15.975700 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000033 (ops 156-160)
I20260812 06:19:15.975745 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000034 (ops 161-165)
I20260812 06:19:15.975785 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000035 (ops 166-170)
I20260812 06:19:15.975824 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000036 (ops 171-175)
I20260812 06:19:15.975864 29720 log.cc:1079] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/035b3060535147c7ae90c0662ebfdd7f/wal-000000037 (ops 176-180)
I20260812 06:19:16.000716 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: LogGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.025s	user 0.001s	sys 0.022s Metrics: {}
I20260812 06:19:16.001175 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:16.023648 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.022s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.024222 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f): 447 bytes on disk
I20260812 06:19:16.024678 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: UndoDeltaBlockGCOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.025218 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:16.036389 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.037087 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:16.203120 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.166s	user 0.127s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836373,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":675,"lbm_read_time_us":12514,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33382,"lbm_writes_lt_1ms":643,"mutex_wait_us":315,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:16.203910 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=14.095187
I20260812 06:19:16.257869 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.054s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.258358 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=2.188937
I20260812 06:19:16.272342 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.272943 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:16.400463 29607 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.891s	user 1.847s	sys 0.118s
I20260812 06:19:16.429581 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.156s	user 0.114s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11936,"lbm_reads_lt_1ms":560,"lbm_write_time_us":30856,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:16.430114 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f): perf score=10.126437
I20260812 06:19:16.456032 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: FlushDeltaMemStoresOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.026s	user 0.018s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12332,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.456498 29789 maintenance_manager.cc:419] P 775c3f5202ef4feea3f0e1314a4ab8ba: Scheduling MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f): perf score=1.000000
I20260812 06:19:16.485133 29607 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.003s	sys 0.000s
I20260812 06:19:16.485846 29607 tablet_server.cc:179] TabletServer@127.28.233.193:0 shutting down...
I20260812 06:19:16.563200 29720 maintenance_manager.cc:643] P 775c3f5202ef4feea3f0e1314a4ab8ba: MajorDeltaCompactionOp(035b3060535147c7ae90c0662ebfdd7f) complete. Timing: real 0.107s	user 0.086s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528784,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":591,"lbm_read_time_us":8192,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20939,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":126,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.564005 29607 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:16.564560 29607 tablet_replica.cc:333] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba: stopping tablet replica
I20260812 06:19:16.564823 29607 raft_consensus.cc:2243] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.565081 29607 raft_consensus.cc:2272] T 035b3060535147c7ae90c0662ebfdd7f P 775c3f5202ef4feea3f0e1314a4ab8ba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.582000 29607 tablet_server.cc:196] TabletServer@127.28.233.193:0 shutdown complete.
I20260812 06:19:16.595436 29607 master.cc:562] Master@127.28.233.254:37713 shutting down...
I20260812 06:19:16.600342 29607 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.600513 29607 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.600570 29607 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7506d5b00b4745ea92978c0bf3c31168: stopping tablet replica
I20260812 06:19:16.613092 29607 master.cc:584] Master@127.28.233.254:37713 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5511 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:16.708233 29607 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.233.254:39507
I20260812 06:19:16.708606 29607 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.710734 29823 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:16.710870 29825 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:16.710870 29828 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:16.711086 29607 server_base.cc:1061] running on GCE node
I20260812 06:19:16.711302 29607 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.711359 29607 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:16.711392 29607 hybrid_clock.cc:648] HybridClock initialized: now 1786515556711391 us; error 0 us; skew 500 ppm
I20260812 06:19:16.712260 29607 webserver.cc:533] Webserver started at http://127.28.233.254:34367/ using document root <none> and password file <none>
I20260812 06:19:16.712452 29607 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.712524 29607 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.712606 29607 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.713019 29607 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/master-0-root/instance:
uuid: "1be525577a364b0095da3517aa4fc1b2"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-5l3k"
I20260812 06:19:16.714708 29607 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.715845 29833 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:16.716169 29607 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.716270 29607 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/master-0-root
uuid: "1be525577a364b0095da3517aa4fc1b2"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-5l3k"
I20260812 06:19:16.716363 29607 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-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:16.731492 29607 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.731957 29607 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.736472 29607 rpc_server.cc:307] RPC server started. Bound to: 127.28.233.254:39507
I20260812 06:19:16.740702 29893 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:16.740988 29892 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.233.254:39507 every 8 connection(s)
I20260812 06:19:16.752249 29893 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2: Bootstrap starting.
I20260812 06:19:16.753192 29893 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.754354 29893 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2: No bootstrap required, opened a new log
I20260812 06:19:16.754855 29893 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER }
I20260812 06:19:16.754971 29893 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.755023 29893 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1be525577a364b0095da3517aa4fc1b2, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.755198 29893 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [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: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER }
I20260812 06:19:16.755308 29893 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.755358 29893 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.755415 29893 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.756165 29893 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER }
I20260812 06:19:16.756318 29893 leader_election.cc:304] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [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: 1be525577a364b0095da3517aa4fc1b2; no voters: 
I20260812 06:19:16.756549 29893 leader_election.cc:290] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.756704 29896 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.756959 29896 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 1 LEADER]: Becoming Leader. State: Replica: 1be525577a364b0095da3517aa4fc1b2, State: Running, Role: LEADER
I20260812 06:19:16.757067 29893 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:16.757128 29896 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [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: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER }
I20260812 06:19:16.757652 29898 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1be525577a364b0095da3517aa4fc1b2. Latest consensus state: current_term: 1 leader_uuid: "1be525577a364b0095da3517aa4fc1b2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER } }
I20260812 06:19:16.757776 29898 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.757630 29897 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1be525577a364b0095da3517aa4fc1b2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be525577a364b0095da3517aa4fc1b2" member_type: VOTER } }
I20260812 06:19:16.757882 29897 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.758414 29903 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:16.759140 29903 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:16.759333 29607 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:16.761564 29903 catalog_manager.cc:1383] Generated new cluster ID: 0d1805cd48aa45559ee1853e4a4a7f32
I20260812 06:19:16.761633 29903 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:16.770103 29903 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:16.770774 29903 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:16.782644 29903 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2: Generated new TSK 0
I20260812 06:19:16.782855 29903 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:16.791998 29607 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.794160 29921 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:16.794137 29607 server_base.cc:1061] running on GCE node
W20260812 06:19:16.794128 29917 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:16.794330 29918 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:16.794580 29607 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.794648 29607 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:16.794665 29607 hybrid_clock.cc:648] HybridClock initialized: now 1786515556794665 us; error 0 us; skew 500 ppm
I20260812 06:19:16.795676 29607 webserver.cc:533] Webserver started at http://127.28.233.193:43081/ using document root <none> and password file <none>
I20260812 06:19:16.795866 29607 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.795929 29607 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.796027 29607 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.796542 29607 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/instance:
uuid: "21accd8deef94d29ae5beb024e98d423"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-5l3k"
I20260812 06:19:16.798802 29607 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:16.800040 29926 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:16.800374 29607 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.800487 29607 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root
uuid: "21accd8deef94d29ae5beb024e98d423"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-5l3k"
I20260812 06:19:16.800594 29607 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-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:16.813549 29607 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.813999 29607 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.814368 29607 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:16.815093 29607 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:16.815166 29607 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.815235 29607 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:16.815274 29607 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.820942 29607 rpc_server.cc:307] RPC server started. Bound to: 127.28.233.193:43231
I20260812 06:19:16.820978 30002 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.233.193:43231 every 8 connection(s)
I20260812 06:19:16.827374 30003 heartbeater.cc:344] Connected to a master server at 127.28.233.254:39507
I20260812 06:19:16.827527 30003 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:16.827826 30003 heartbeater.cc:507] Master 127.28.233.254:39507 requested a full tablet report, sending...
I20260812 06:19:16.828662 29852 ts_manager.cc:194] Registered new tserver with Master: 21accd8deef94d29ae5beb024e98d423 (127.28.233.193:43231)
I20260812 06:19:16.829376 29852 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43982
I20260812 06:19:16.829542 29607 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0079996s
I20260812 06:19:16.838033 29852 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43992:
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:16.847769 29960 tablet_service.cc:1511] Processing CreateTablet for tablet a5d88c21abfb47eabe237ea2b240db3c (DEFAULT_TABLE table=heavy-update-compaction-test [id=a279032358d241ca91ea1686790229f1]), partition=
I20260812 06:19:16.848215 29960 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a5d88c21abfb47eabe237ea2b240db3c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.850663 30015 tablet_bootstrap.cc:492] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Bootstrap starting.
I20260812 06:19:16.852085 30015 tablet_bootstrap.cc:654] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.853746 30015 tablet_bootstrap.cc:492] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: No bootstrap required, opened a new log
I20260812 06:19:16.853863 30015 ts_tablet_manager.cc:1403] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:16.854445 30015 raft_consensus.cc:359] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21accd8deef94d29ae5beb024e98d423" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 43231 } }
I20260812 06:19:16.854621 30015 raft_consensus.cc:385] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.854664 30015 raft_consensus.cc:740] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 21accd8deef94d29ae5beb024e98d423, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.854826 30015 consensus_queue.cc:260] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [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: "21accd8deef94d29ae5beb024e98d423" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 43231 } }
I20260812 06:19:16.854938 30015 raft_consensus.cc:399] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.854981 30015 raft_consensus.cc:493] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.855057 30015 raft_consensus.cc:3060] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.856204 30015 raft_consensus.cc:515] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21accd8deef94d29ae5beb024e98d423" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 43231 } }
I20260812 06:19:16.856375 30015 leader_election.cc:304] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [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: 21accd8deef94d29ae5beb024e98d423; no voters: 
I20260812 06:19:16.856665 30015 leader_election.cc:290] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.856833 30017 raft_consensus.cc:2804] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.857079 30015 ts_tablet_manager.cc:1434] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:16.857100 30003 heartbeater.cc:499] Master 127.28.233.254:39507 was elected leader, sending a full tablet report...
I20260812 06:19:16.857120 30017 raft_consensus.cc:697] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 1 LEADER]: Becoming Leader. State: Replica: 21accd8deef94d29ae5beb024e98d423, State: Running, Role: LEADER
I20260812 06:19:16.857323 30017 consensus_queue.cc:237] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [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: "21accd8deef94d29ae5beb024e98d423" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 43231 } }
I20260812 06:19:16.858846 29852 catalog_manager.cc:5719] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 reported cstate change: term changed from 0 to 1, leader changed from <none> to 21accd8deef94d29ae5beb024e98d423 (127.28.233.193). New cstate: current_term: 1 leader_uuid: "21accd8deef94d29ae5beb024e98d423" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21accd8deef94d29ae5beb024e98d423" member_type: VOTER last_known_addr { host: "127.28.233.193" port: 43231 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:16.918720 29607 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.012s	sys 0.011s
I20260812 06:19:17.072225 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=19.054940
I20260812 06:19:17.232537 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.160s	user 0.115s	sys 0.043s Metrics: {"bytes_written":12717736,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":987,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41454,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1550}
I20260812 06:19:17.233167 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling LogGCOp(a5d88c21abfb47eabe237ea2b240db3c): free 20743880 bytes of WAL
I20260812 06:19:17.233430 29932 log_reader.cc:385] T a5d88c21abfb47eabe237ea2b240db3c: removed 2 log segments from log reader
I20260812 06:19:17.233492 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000001 (ops 1-6)
I20260812 06:19:17.233533 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000002 (ops 7-11)
I20260812 06:19:17.239308 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: LogGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:17.239785 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c): 16411393 bytes on disk
I20260812 06:19:17.240240 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c) 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:17.240636 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.255548 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.015s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3788,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.256029 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.267000 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.267441 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:17.437610 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.170s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":552,"lbm_read_time_us":13199,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28800,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":333,"threads_started":5,"update_count":2500}
I20260812 06:19:17.438217 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:17.492398 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.054s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20795,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.492942 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.506784 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.507356 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:17.673840 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.166s	user 0.117s	sys 0.048s 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":441,"lbm_read_time_us":13478,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32765,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30464,"update_count":2500}
I20260812 06:19:17.674546 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=11.118625
I20260812 06:19:17.707413 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14301,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.707930 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.725199 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.725780 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:17.855329 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.129s	user 0.086s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":7919,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24225,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.856105 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=11.118625
I20260812 06:19:17.900485 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13969,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.901172 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.928465 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5298,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.928999 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:17.939803 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.940364 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:18.122464 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.182s	user 0.104s	sys 0.073s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":422,"lbm_read_time_us":12440,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31160,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:19:18.123138 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:18.187191 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.064s	user 0.030s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21842,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.187799 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:18.198587 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.199075 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:18.397846 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.199s	user 0.123s	sys 0.065s 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":172,"lbm_read_time_us":13476,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31828,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:18.398605 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:18.461310 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.062s	user 0.024s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22116,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.461957 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:18.479977 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.480650 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:18.518060 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.037s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1357,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2452,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:18.518810 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling LogGCOp(a5d88c21abfb47eabe237ea2b240db3c): free 115943174 bytes of WAL
I20260812 06:19:18.519037 29932 log_reader.cc:385] T a5d88c21abfb47eabe237ea2b240db3c: removed 11 log segments from log reader
I20260812 06:19:18.519079 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000003 (ops 12-16)
I20260812 06:19:18.519107 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000004 (ops 17-21)
I20260812 06:19:18.519168 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000005 (ops 22-26)
I20260812 06:19:18.519214 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000006 (ops 27-31)
I20260812 06:19:18.519255 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000007 (ops 32-36)
I20260812 06:19:18.519294 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000008 (ops 37-41)
I20260812 06:19:18.519332 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000009 (ops 42-46)
I20260812 06:19:18.519369 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000010 (ops 47-51)
I20260812 06:19:18.519407 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000011 (ops 52-56)
I20260812 06:19:18.519445 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000012 (ops 57-61)
I20260812 06:19:18.519484 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000013 (ops 62-66)
I20260812 06:19:18.545238 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: LogGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:18.545734 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c): 462 bytes on disk
I20260812 06:19:18.546334 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.546924 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:18.564527 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.017s	user 0.006s	sys 0.002s 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:19:18.564996 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:18.575486 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.576088 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:18.829308 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.253s	user 0.148s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":813,"lbm_read_time_us":16909,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40426,"lbm_writes_lt_1ms":743,"mutex_wait_us":70,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:19:18.830135 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=18.063937
I20260812 06:19:18.905385 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.075s	user 0.048s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32804,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.905949 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:18.920089 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.920850 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:19.098132 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.177s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":988,"lbm_read_time_us":12172,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32287,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:19:19.098920 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:19.147930 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.049s	user 0.029s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20784,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.148566 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:19.173060 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.024s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.173570 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:19.184512 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.185046 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:19.360024 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.175s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":219,"lbm_read_time_us":12733,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34413,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3000}
I20260812 06:19:19.360744 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:19.412210 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.051s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:19.412724 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:19.424168 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.424655 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:19.584503 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.160s	user 0.127s	sys 0.030s 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":151,"lbm_read_time_us":11386,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30879,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:19:19.585355 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=12.110812
I20260812 06:19:19.628104 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.043s	user 0.026s	sys 0.015s Metrics: {"bytes_written":13620266,"delete_count":0,"lbm_write_time_us":18637,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:19:19.628875 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.196750
I20260812 06:19:19.654649 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.026s	user 0.013s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:19.655252 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:19.670889 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.671568 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:19.854780 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.183s	user 0.110s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":395,"lbm_read_time_us":13694,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32177,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:19:19.855469 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:19.912331 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.057s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23112,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.912864 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:19.949386 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.036s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1449,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1681,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:19.950314 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling LogGCOp(a5d88c21abfb47eabe237ea2b240db3c): free 121006388 bytes of WAL
I20260812 06:19:19.950670 29932 log_reader.cc:385] T a5d88c21abfb47eabe237ea2b240db3c: removed 12 log segments from log reader
I20260812 06:19:19.950809 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000014 (ops 67-71)
I20260812 06:19:19.950891 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000015 (ops 72-76)
I20260812 06:19:19.950939 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000016 (ops 77-81)
I20260812 06:19:19.950984 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000017 (ops 82-86)
I20260812 06:19:19.951025 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000018 (ops 87-91)
I20260812 06:19:19.951050 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000019 (ops 92-96)
I20260812 06:19:19.951072 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000020 (ops 97-100)
I20260812 06:19:19.951102 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000021 (ops 101-105)
I20260812 06:19:19.951146 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000022 (ops 106-110)
I20260812 06:19:19.951188 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000023 (ops 111-115)
I20260812 06:19:19.951259 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000024 (ops 116-120)
I20260812 06:19:19.951323 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000025 (ops 121-125)
I20260812 06:19:19.976537 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: LogGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:19.977026 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c): 463 bytes on disk
I20260812 06:19:19.977551 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.978121 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=6.157687
I20260812 06:19:20.012672 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.034s	user 0.015s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11839,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:20.013302 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:20.243716 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.230s	user 0.154s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":988,"lbm_read_time_us":16553,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35567,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":68224,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:19:20.244551 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:20.315084 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.070s	user 0.036s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29930,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.315766 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:20.334604 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.335309 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:20.557543 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.222s	user 0.154s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":18733,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33045,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.558245 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=18.063937
I20260812 06:19:20.620311 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.062s	user 0.045s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28421,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.620872 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:20.633250 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.633736 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:20.838155 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.204s	user 0.136s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"lbm_read_time_us":12756,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34559,"lbm_writes_lt_1ms":643,"mutex_wait_us":422,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:20.838850 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=16.079562
I20260812 06:19:20.921648 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.083s	user 0.047s	sys 0.021s Metrics: {"bytes_written":17722676,"delete_count":0,"lbm_write_time_us":33776,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2160}
I20260812 06:19:20.922204 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=5.165500
I20260812 06:19:20.942034 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":6892310,"delete_count":0,"lbm_write_time_us":7984,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:19:20.942633 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:21.157918 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.215s	user 0.144s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877108,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2999,"lbm_read_time_us":14389,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36207,"lbm_writes_lt_1ms":643,"mutex_wait_us":2487,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:19:21.158972 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:21.229372 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.070s	user 0.024s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29306,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.229928 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=3.181125
I20260812 06:19:21.242079 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":4700,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:21.242673 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:21.257562 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":5423,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:21.258234 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:21.485659 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.227s	user 0.173s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":377,"lbm_read_time_us":13236,"lbm_reads_lt_1ms":673,"lbm_write_time_us":42378,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:21.486606 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=14.095187
I20260812 06:19:21.541437 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.055s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21927,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.542212 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=3.181125
I20260812 06:19:21.558060 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6170,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.558674 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:21.572304 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5034,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.572865 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:21.605751 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushMRSOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1751,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1424,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:21.606614 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling LogGCOp(a5d88c21abfb47eabe237ea2b240db3c): free 124257560 bytes of WAL
I20260812 06:19:21.606868 29932 log_reader.cc:385] T a5d88c21abfb47eabe237ea2b240db3c: removed 12 log segments from log reader
I20260812 06:19:21.606914 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000026 (ops 126-130)
I20260812 06:19:21.606945 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000027 (ops 131-135)
I20260812 06:19:21.607012 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000028 (ops 136-140)
I20260812 06:19:21.607045 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000029 (ops 141-145)
I20260812 06:19:21.607085 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000030 (ops 146-150)
I20260812 06:19:21.607148 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000031 (ops 151-154)
I20260812 06:19:21.607191 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000032 (ops 155-159)
I20260812 06:19:21.607224 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000033 (ops 160-164)
I20260812 06:19:21.607265 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000034 (ops 165-169)
I20260812 06:19:21.607302 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000035 (ops 170-174)
I20260812 06:19:21.607342 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000036 (ops 175-179)
I20260812 06:19:21.607378 29932 log.cc:1079] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: Deleting log segment in path: /tmp/dist-test-taske6u8I9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551186079-29607-0/minicluster-data/ts-0-root/wals/a5d88c21abfb47eabe237ea2b240db3c/wal-000000037 (ops 180-184)
I20260812 06:19:21.636519 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: LogGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.030s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:19:21.637086 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c): 472 bytes on disk
I20260812 06:19:21.637560 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: UndoDeltaBlockGCOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.638197 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=3.181125
I20260812 06:19:21.653718 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.015s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4523,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.654440 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:21.665436 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4069,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.666170 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:21.918939 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.252s	user 0.160s	sys 0.092s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082254,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":698,"lbm_read_time_us":18083,"lbm_reads_lt_1ms":875,"lbm_write_time_us":46170,"lbm_writes_lt_1ms":843,"mutex_wait_us":356,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":88,"threads_started":1,"update_count":4000}
I20260812 06:19:21.919982 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=18.063937
I20260812 06:19:21.980995 29607 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.062s	user 1.904s	sys 0.129s
I20260812 06:19:21.985436 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.065s	user 0.042s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29657,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.985991 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=2.188937
I20260812 06:19:21.998778 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: FlushDeltaMemStoresOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.999264 30004 maintenance_manager.cc:419] P 21accd8deef94d29ae5beb024e98d423: Scheduling MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c): perf score=1.000000
I20260812 06:19:22.033938 29607 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.001s	sys 0.000s
I20260812 06:19:22.034585 29607 tablet_server.cc:179] TabletServer@127.28.233.193:0 shutting down...
I20260812 06:19:22.138366 29932 maintenance_manager.cc:643] P 21accd8deef94d29ae5beb024e98d423: MajorDeltaCompactionOp(a5d88c21abfb47eabe237ea2b240db3c) complete. Timing: real 0.139s	user 0.101s	sys 0.037s Metrics: {"cfile_cache_hit":452,"cfile_cache_hit_bytes":18502642,"cfile_cache_miss":180,"cfile_cache_miss_bytes":10374460,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":4241,"lbm_reads_lt_1ms":212,"lbm_write_time_us":31006,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":3000}
I20260812 06:19:22.139235 29607 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:22.139531 29607 tablet_replica.cc:333] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423: stopping tablet replica
I20260812 06:19:22.139679 29607 raft_consensus.cc:2243] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.139895 29607 raft_consensus.cc:2272] T a5d88c21abfb47eabe237ea2b240db3c P 21accd8deef94d29ae5beb024e98d423 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.144969 29607 tablet_server.cc:196] TabletServer@127.28.233.193:0 shutdown complete.
I20260812 06:19:22.191428 29607 master.cc:562] Master@127.28.233.254:39507 shutting down...
I20260812 06:19:22.195407 29607 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.195619 29607 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.195722 29607 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1be525577a364b0095da3517aa4fc1b2: stopping tablet replica
I20260812 06:19:22.208590 29607 master.cc:584] Master@127.28.233.254:39507 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5593 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11106 ms total)

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