[==========] 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:16:39.870486 12861 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.143.126:34331
I20260812 06:16:39.871539 12861 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:16:39.872154 12861 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:39.879087 12868 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:16:39.879189 12870 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:16:39.879340 12861 server_base.cc:1061] running on GCE node
W20260812 06:16:39.879474 12874 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:16:39.880039 12861 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:39.880162 12861 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:16:39.880210 12861 hybrid_clock.cc:648] HybridClock initialized: now 1786515399880209 us; error 0 us; skew 500 ppm
I20260812 06:16:39.882126 12861 webserver.cc:533] Webserver started at http://127.12.143.126:39601/ using document root <none> and password file <none>
I20260812 06:16:39.882776 12861 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:39.882848 12861 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:39.883093 12861 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:39.884842 12861 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/master-0-root/instance:
uuid: "70a548c3cb1c4831a5d5993211b7a526"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-j2vl"
I20260812 06:16:39.888599 12861 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.003s
I20260812 06:16:39.890878 12884 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:16:39.892055 12861 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:39.892220 12861 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/master-0-root
uuid: "70a548c3cb1c4831a5d5993211b7a526"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-j2vl"
I20260812 06:16:39.892349 12861 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-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:16:39.913177 12861 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:39.913842 12861 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:16:39.914024 12861 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:39.922276 12861 rpc_server.cc:307] RPC server started. Bound to: 127.12.143.126:34331
I20260812 06:16:39.922312 12989 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.143.126:34331 every 8 connection(s)
I20260812 06:16:39.924496 12990 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:16:39.929878 12990 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: Bootstrap starting.
I20260812 06:16:39.932156 12990 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:39.933017 12990 log.cc:826] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:39.934631 12990 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: No bootstrap required, opened a new log
I20260812 06:16:39.937292 12990 raft_consensus.cc:359] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER }
I20260812 06:16:39.937525 12990 raft_consensus.cc:385] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:39.937597 12990 raft_consensus.cc:740] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 70a548c3cb1c4831a5d5993211b7a526, State: Initialized, Role: FOLLOWER
I20260812 06:16:39.938180 12990 consensus_queue.cc:260] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [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: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER }
I20260812 06:16:39.938336 12990 raft_consensus.cc:399] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:39.938432 12990 raft_consensus.cc:493] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:39.938578 12990 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:39.939371 12990 raft_consensus.cc:515] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER }
I20260812 06:16:39.939805 12990 leader_election.cc:304] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [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: 70a548c3cb1c4831a5d5993211b7a526; no voters: 
I20260812 06:16:39.940114 12990 leader_election.cc:290] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:39.940289 12998 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:39.940593 12998 raft_consensus.cc:697] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 1 LEADER]: Becoming Leader. State: Replica: 70a548c3cb1c4831a5d5993211b7a526, State: Running, Role: LEADER
I20260812 06:16:39.940991 12998 consensus_queue.cc:237] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [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: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER }
I20260812 06:16:39.941143 12990 sys_catalog.cc:565] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:39.942899 12999 sys_catalog.cc:455] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "70a548c3cb1c4831a5d5993211b7a526" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER } }
I20260812 06:16:39.942943 13000 sys_catalog.cc:455] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 70a548c3cb1c4831a5d5993211b7a526. Latest consensus state: current_term: 1 leader_uuid: "70a548c3cb1c4831a5d5993211b7a526" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70a548c3cb1c4831a5d5993211b7a526" member_type: VOTER } }
I20260812 06:16:39.943012 12999 sys_catalog.cc:458] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:39.943037 13000 sys_catalog.cc:458] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:39.943436 13018 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:39.943605 12861 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:39.945577 13018 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:39.949725 13018 catalog_manager.cc:1383] Generated new cluster ID: f1951d36a80541e2bd6dbac4a1ff0367
I20260812 06:16:39.949788 13018 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:39.970175 13018 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:39.971300 13018 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:39.978175 13018 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: Generated new TSK 0
I20260812 06:16:39.978878 13018 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:40.008499 12861 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:40.011401 13033 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:16:40.011418 13029 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:16:40.011523 12861 server_base.cc:1061] running on GCE node
W20260812 06:16:40.011473 13037 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:16:40.011981 12861 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:40.012027 12861 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:16:40.012045 12861 hybrid_clock.cc:648] HybridClock initialized: now 1786515400012045 us; error 0 us; skew 500 ppm
I20260812 06:16:40.013080 12861 webserver.cc:533] Webserver started at http://127.12.143.65:41439/ using document root <none> and password file <none>
I20260812 06:16:40.013269 12861 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:40.013350 12861 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:40.013464 12861 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:40.013888 12861 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/instance:
uuid: "4ad329b78fbc4081b47acc4a87e81a6f"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-j2vl"
I20260812 06:16:40.015475 12861 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:40.016479 13046 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:16:40.016744 12861 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:40.016821 12861 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root
uuid: "4ad329b78fbc4081b47acc4a87e81a6f"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-j2vl"
I20260812 06:16:40.016912 12861 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-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:16:40.036465 12861 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:40.037319 12861 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:40.037851 12861 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:40.038759 12861 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:40.038812 12861 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:40.038885 12861 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:40.038929 12861 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:40.045774 12861 rpc_server.cc:307] RPC server started. Bound to: 127.12.143.65:39239
I20260812 06:16:40.045886 13188 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.143.65:39239 every 8 connection(s)
I20260812 06:16:40.059342 13189 heartbeater.cc:344] Connected to a master server at 127.12.143.126:34331
I20260812 06:16:40.059609 13189 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:40.060101 13189 heartbeater.cc:507] Master 127.12.143.126:34331 requested a full tablet report, sending...
I20260812 06:16:40.061560 12924 ts_manager.cc:194] Registered new tserver with Master: 4ad329b78fbc4081b47acc4a87e81a6f (127.12.143.65:39239)
I20260812 06:16:40.062160 12861 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015710346s
I20260812 06:16:40.063007 12924 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51250
I20260812 06:16:40.072748 12924 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51262:
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:16:40.088418 13114 tablet_service.cc:1511] Processing CreateTablet for tablet b084bca6df884058b6b9d05b792adb8f (DEFAULT_TABLE table=heavy-update-compaction-test [id=fcd50b6433604347b1423d9ccda4818d]), partition=
I20260812 06:16:40.088934 13114 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b084bca6df884058b6b9d05b792adb8f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:40.091871 13205 tablet_bootstrap.cc:492] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Bootstrap starting.
I20260812 06:16:40.092742 13205 tablet_bootstrap.cc:654] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:40.093921 13205 tablet_bootstrap.cc:492] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: No bootstrap required, opened a new log
I20260812 06:16:40.094007 13205 ts_tablet_manager.cc:1403] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:40.094513 13205 raft_consensus.cc:359] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad329b78fbc4081b47acc4a87e81a6f" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 39239 } }
I20260812 06:16:40.094614 13205 raft_consensus.cc:385] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:40.094637 13205 raft_consensus.cc:740] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4ad329b78fbc4081b47acc4a87e81a6f, State: Initialized, Role: FOLLOWER
I20260812 06:16:40.094838 13205 consensus_queue.cc:260] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [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: "4ad329b78fbc4081b47acc4a87e81a6f" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 39239 } }
I20260812 06:16:40.094921 13205 raft_consensus.cc:399] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:40.094949 13205 raft_consensus.cc:493] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:40.095024 13205 raft_consensus.cc:3060] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:40.095872 13205 raft_consensus.cc:515] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad329b78fbc4081b47acc4a87e81a6f" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 39239 } }
I20260812 06:16:40.096032 13205 leader_election.cc:304] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [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: 4ad329b78fbc4081b47acc4a87e81a6f; no voters: 
I20260812 06:16:40.096263 13205 leader_election.cc:290] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:40.096395 13207 raft_consensus.cc:2804] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:40.096588 13207 raft_consensus.cc:697] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 1 LEADER]: Becoming Leader. State: Replica: 4ad329b78fbc4081b47acc4a87e81a6f, State: Running, Role: LEADER
I20260812 06:16:40.096686 13205 ts_tablet_manager.cc:1434] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:40.096774 13207 consensus_queue.cc:237] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [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: "4ad329b78fbc4081b47acc4a87e81a6f" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 39239 } }
I20260812 06:16:40.097069 13189 heartbeater.cc:499] Master 127.12.143.126:34331 was elected leader, sending a full tablet report...
I20260812 06:16:40.099643 12924 catalog_manager.cc:5719] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f reported cstate change: term changed from 0 to 1, leader changed from <none> to 4ad329b78fbc4081b47acc4a87e81a6f (127.12.143.65). New cstate: current_term: 1 leader_uuid: "4ad329b78fbc4081b47acc4a87e81a6f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad329b78fbc4081b47acc4a87e81a6f" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 39239 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:40.161775 12861 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.016s	sys 0.008s
I20260812 06:16:40.297139 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushMRSOp(b084bca6df884058b6b9d05b792adb8f): perf score=15.086190
I20260812 06:16:40.458657 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushMRSOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.161s	user 0.125s	sys 0.027s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":183,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":788,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39061,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":111,"threads_started":1,"update_count":1450}
I20260812 06:16:40.459658 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling LogGCOp(b084bca6df884058b6b9d05b792adb8f): free 20743880 bytes of WAL
I20260812 06:16:40.460018 13063 log_reader.cc:385] T b084bca6df884058b6b9d05b792adb8f: removed 2 log segments from log reader
I20260812 06:16:40.460086 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000001 (ops 1-6)
I20260812 06:16:40.460156 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000002 (ops 7-11)
I20260812 06:16:40.465859 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: LogGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:40.466332 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f): 12719218 bytes on disk
I20260812 06:16:40.467063 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:16:40.467495 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:40.483039 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.483546 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:40.609750 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.126s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":652,"lbm_read_time_us":8226,"lbm_reads_lt_1ms":450,"lbm_write_time_us":23117,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":355,"threads_started":5,"update_count":1950}
I20260812 06:16:40.610476 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:40.654747 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.044s	user 0.015s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13515,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.655202 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:40.665700 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.666230 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:40.781531 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.115s	user 0.077s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":7543,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23674,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:16:40.782195 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:40.824378 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.042s	user 0.013s	sys 0.018s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14652,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.824822 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:40.835394 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.835935 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:40.965477 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.129s	user 0.099s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":8549,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26511,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:40.966221 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:41.022627 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.056s	user 0.016s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13889,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.023280 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:41.033824 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.034231 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:41.176573 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.142s	user 0.093s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":910,"lbm_read_time_us":11002,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22358,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.177071 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:41.228129 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.051s	user 0.035s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17532,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.228636 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:41.244215 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.244856 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:41.368216 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.123s	user 0.095s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":8368,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25376,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:16:41.368906 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:41.414266 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.045s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.414811 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:41.425861 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.426520 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:41.546182 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.119s	user 0.095s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":514,"lbm_read_time_us":8267,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22245,"lbm_writes_lt_1ms":443,"mutex_wait_us":284,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:16:41.546872 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:41.592712 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.046s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16401,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.593448 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:41.605225 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.605720 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:41.752238 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.146s	user 0.110s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1652,"lbm_read_time_us":10483,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24626,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:16:41.752822 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:41.795102 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.042s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17791,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:41.795579 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:41.806519 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.807291 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushMRSOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:41.839061 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushMRSOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.032s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":307,"dirs.run_wall_time_us":1351,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1695,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:41.839865 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling LogGCOp(b084bca6df884058b6b9d05b792adb8f): free 124710298 bytes of WAL
I20260812 06:16:41.840103 13063 log_reader.cc:385] T b084bca6df884058b6b9d05b792adb8f: removed 12 log segments from log reader
I20260812 06:16:41.840148 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000003 (ops 12-16)
I20260812 06:16:41.840178 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000004 (ops 17-21)
I20260812 06:16:41.840247 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000005 (ops 22-26)
I20260812 06:16:41.840291 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000006 (ops 27-31)
I20260812 06:16:41.840332 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000007 (ops 32-36)
I20260812 06:16:41.840381 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000008 (ops 37-41)
I20260812 06:16:41.840421 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000009 (ops 42-46)
I20260812 06:16:41.840458 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000010 (ops 47-51)
I20260812 06:16:41.840498 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000011 (ops 52-56)
I20260812 06:16:41.840539 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000012 (ops 57-61)
I20260812 06:16:41.840580 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000013 (ops 62-66)
I20260812 06:16:41.840620 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000014 (ops 67-71)
I20260812 06:16:41.867928 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: LogGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:41.868386 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f): 482 bytes on disk
I20260812 06:16:41.868999 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f) 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:16:41.869678 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=4.173312
I20260812 06:16:41.890767 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.021s	user 0.012s	sys 0.008s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:16:41.891256 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.196750
I20260812 06:16:41.899107 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2623,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:16:41.899556 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:42.113070 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.213s	user 0.117s	sys 0.084s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":727,"lbm_read_time_us":14987,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35362,"lbm_writes_lt_1ms":643,"mutex_wait_us":355,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:16:42.113893 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=14.095187
I20260812 06:16:42.174364 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.060s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.174978 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:42.191395 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.191956 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:42.360610 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.168s	user 0.116s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":13287,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28282,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:42.361212 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:42.396513 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.033s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14428,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.397130 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:42.419679 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.022s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.420169 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:42.553910 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.134s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":686,"lbm_read_time_us":7144,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24739,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:42.554597 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=11.118625
I20260812 06:16:42.593624 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16928,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:42.594367 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:42.609395 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5110,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.609927 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:42.732574 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.122s	user 0.082s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":358,"lbm_read_time_us":8786,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24296,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:42.733222 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:42.773450 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.040s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15478,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.774015 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:42.788777 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.789330 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:42.911243 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.122s	user 0.090s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":692,"lbm_read_time_us":8194,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23862,"lbm_writes_lt_1ms":443,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.911976 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:42.965296 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.053s	user 0.029s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.965852 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:42.976207 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.976675 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:43.127233 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.150s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1022,"lbm_read_time_us":11390,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25004,"lbm_writes_lt_1ms":443,"mutex_wait_us":258,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:43.127933 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:43.174943 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.047s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16965,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.175375 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:43.185716 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.186388 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:43.308669 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.122s	user 0.082s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":8882,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23141,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.309284 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:43.353619 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.044s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15500,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.354156 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:43.365841 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.366372 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushMRSOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:43.398952 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushMRSOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1176,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1487,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:43.399621 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling LogGCOp(b084bca6df884058b6b9d05b792adb8f): free 124710317 bytes of WAL
I20260812 06:16:43.399852 13063 log_reader.cc:385] T b084bca6df884058b6b9d05b792adb8f: removed 12 log segments from log reader
I20260812 06:16:43.399899 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000015 (ops 72-76)
I20260812 06:16:43.399926 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000016 (ops 77-81)
I20260812 06:16:43.399986 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000017 (ops 82-86)
I20260812 06:16:43.400031 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000018 (ops 87-91)
I20260812 06:16:43.400050 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000019 (ops 92-96)
I20260812 06:16:43.400103 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000020 (ops 97-101)
I20260812 06:16:43.400147 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000021 (ops 102-106)
I20260812 06:16:43.400190 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000022 (ops 107-111)
I20260812 06:16:43.400228 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000023 (ops 112-116)
I20260812 06:16:43.400266 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000024 (ops 117-121)
I20260812 06:16:43.400305 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000025 (ops 122-126)
I20260812 06:16:43.400343 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000026 (ops 127-131)
I20260812 06:16:43.427997 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: LogGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:43.428439 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f): 482 bytes on disk
I20260812 06:16:43.428941 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.429646 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=3.181125
I20260812 06:16:43.446986 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6822,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:43.447494 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling LogGCOp(b084bca6df884058b6b9d05b792adb8f): free 12017954 bytes of WAL
I20260812 06:16:43.447727 13063 log_reader.cc:385] T b084bca6df884058b6b9d05b792adb8f: removed 1 log segments from log reader
I20260812 06:16:43.447800 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000027 (ops 132-136)
I20260812 06:16:43.450071 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: LogGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:43.450408 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:43.460680 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:43.461159 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:43.633651 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.172s	user 0.126s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":584,"lbm_read_time_us":12619,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33660,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:16:43.634364 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=14.095187
I20260812 06:16:43.688963 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.054s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.689535 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:43.702785 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.703747 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:43.872632 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.169s	user 0.107s	sys 0.052s 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":707,"lbm_read_time_us":12013,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30651,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":99584,"update_count":2500}
I20260812 06:16:43.873271 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=14.095187
I20260812 06:16:43.918725 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18233,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.919565 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:44.080976 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.161s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":598,"lbm_read_time_us":11714,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23967,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:16:44.081568 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=14.095187
I20260812 06:16:44.134780 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.053s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.135350 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:44.148110 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.148572 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:44.324955 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.176s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":10540,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30659,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:44.325716 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=14.095187
I20260812 06:16:44.383906 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.058s	user 0.030s	sys 0.018s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22535,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.384418 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:44.395949 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.396456 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:44.544064 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.147s	user 0.119s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":826,"lbm_read_time_us":11544,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30246,"lbm_writes_lt_1ms":543,"mutex_wait_us":114,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:16:44.544760 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:44.590049 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18335,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.590670 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:44.606348 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.606992 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:44.737509 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.130s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":9206,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25635,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:16:44.738337 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:44.773892 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.035s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14395,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.774483 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushMRSOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:44.822568 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushMRSOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.048s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1469,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:44.823361 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling LogGCOp(b084bca6df884058b6b9d05b792adb8f): free 112239552 bytes of WAL
I20260812 06:16:44.823634 13063 log_reader.cc:385] T b084bca6df884058b6b9d05b792adb8f: removed 11 log segments from log reader
I20260812 06:16:44.823699 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000028 (ops 137-141)
I20260812 06:16:44.823738 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000029 (ops 142-146)
I20260812 06:16:44.823763 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000030 (ops 147-151)
I20260812 06:16:44.823792 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000031 (ops 152-156)
I20260812 06:16:44.823822 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000032 (ops 157-160)
I20260812 06:16:44.823845 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000033 (ops 161-165)
I20260812 06:16:44.823881 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000034 (ops 166-170)
I20260812 06:16:44.823907 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000035 (ops 171-175)
I20260812 06:16:44.823930 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000036 (ops 176-180)
I20260812 06:16:44.823959 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000037 (ops 181-185)
I20260812 06:16:44.823988 13063 log.cc:1079] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/b084bca6df884058b6b9d05b792adb8f/wal-000000038 (ops 186-190)
I20260812 06:16:44.851982 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: LogGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:44.852617 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=6.157687
I20260812 06:16:44.879356 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.027s	user 0.019s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10136,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:44.879905 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f): 460 bytes on disk
I20260812 06:16:44.880330 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: UndoDeltaBlockGCOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.880882 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=2.188937
I20260812 06:16:44.892580 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.893301 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f): perf score=1.000000
I20260812 06:16:45.024268 12861 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.862s	user 1.800s	sys 0.127s
I20260812 06:16:45.059612 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: MajorDeltaCompactionOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.166s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":12274,"lbm_reads_lt_1ms":669,"lbm_write_time_us":36298,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3000}
I20260812 06:16:45.060096 13190 maintenance_manager.cc:419] P 4ad329b78fbc4081b47acc4a87e81a6f: Scheduling FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f): perf score=10.126437
I20260812 06:16:45.096841 12861 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:16:45.097759 12861 tablet_server.cc:179] TabletServer@127.12.143.65:0 shutting down...
I20260812 06:16:45.109880 13063 maintenance_manager.cc:643] P 4ad329b78fbc4081b47acc4a87e81a6f: FlushDeltaMemStoresOp(b084bca6df884058b6b9d05b792adb8f) complete. Timing: real 0.050s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":30525,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":301,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:16:45.110425 12861 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:45.110785 12861 tablet_replica.cc:333] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f: stopping tablet replica
I20260812 06:16:45.111022 12861 raft_consensus.cc:2243] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:45.111315 12861 raft_consensus.cc:2272] T b084bca6df884058b6b9d05b792adb8f P 4ad329b78fbc4081b47acc4a87e81a6f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:45.127265 12861 tablet_server.cc:196] TabletServer@127.12.143.65:0 shutdown complete.
I20260812 06:16:45.136512 12861 master.cc:562] Master@127.12.143.126:34331 shutting down...
I20260812 06:16:45.139940 12861 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:45.140102 12861 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:45.140156 12861 tablet_replica.cc:333] T 00000000000000000000000000000000 P 70a548c3cb1c4831a5d5993211b7a526: stopping tablet replica
I20260812 06:16:45.152657 12861 master.cc:584] Master@127.12.143.126:34331 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5368 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:45.238909 12861 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.143.126:44297
I20260812 06:16:45.239331 12861 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:45.241618 13236 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:16:45.241683 12861 server_base.cc:1061] running on GCE node
W20260812 06:16:45.241606 13243 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:16:45.241670 13238 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:16:45.242029 12861 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:45.242091 12861 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:16:45.242116 12861 hybrid_clock.cc:648] HybridClock initialized: now 1786515405242116 us; error 0 us; skew 500 ppm
I20260812 06:16:45.242942 12861 webserver.cc:533] Webserver started at http://127.12.143.126:39061/ using document root <none> and password file <none>
I20260812 06:16:45.243140 12861 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:45.243198 12861 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:45.243278 12861 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:45.243693 12861 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/master-0-root/instance:
uuid: "b873454109a6498ebb87844cb008f654"
format_stamp: "Formatted at 2026-08-12 06:16:45 on dist-test-slave-j2vl"
I20260812 06:16:45.245209 12861 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:45.246510 13249 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:16:45.246810 12861 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:45.246917 12861 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/master-0-root
uuid: "b873454109a6498ebb87844cb008f654"
format_stamp: "Formatted at 2026-08-12 06:16:45 on dist-test-slave-j2vl"
I20260812 06:16:45.247014 12861 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-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:16:45.262704 12861 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:45.263155 12861 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:45.267627 12861 rpc_server.cc:307] RPC server started. Bound to: 127.12.143.126:44297
I20260812 06:16:45.269330 13354 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.143.126:44297 every 8 connection(s)
I20260812 06:16:45.269784 13357 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:16:45.285894 13357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654: Bootstrap starting.
I20260812 06:16:45.286796 13357 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:45.287973 13357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654: No bootstrap required, opened a new log
I20260812 06:16:45.288362 13357 raft_consensus.cc:359] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b873454109a6498ebb87844cb008f654" member_type: VOTER }
I20260812 06:16:45.288455 13357 raft_consensus.cc:385] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:45.288477 13357 raft_consensus.cc:740] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b873454109a6498ebb87844cb008f654, State: Initialized, Role: FOLLOWER
I20260812 06:16:45.288586 13357 consensus_queue.cc:260] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [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: "b873454109a6498ebb87844cb008f654" member_type: VOTER }
I20260812 06:16:45.288646 13357 raft_consensus.cc:399] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:45.288683 13357 raft_consensus.cc:493] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:45.288719 13357 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:45.289566 13357 raft_consensus.cc:515] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b873454109a6498ebb87844cb008f654" member_type: VOTER }
I20260812 06:16:45.289685 13357 leader_election.cc:304] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [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: b873454109a6498ebb87844cb008f654; no voters: 
I20260812 06:16:45.289888 13357 leader_election.cc:290] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:45.289994 13362 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:45.290211 13362 raft_consensus.cc:697] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 1 LEADER]: Becoming Leader. State: Replica: b873454109a6498ebb87844cb008f654, State: Running, Role: LEADER
I20260812 06:16:45.290400 13357 sys_catalog.cc:565] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:45.290398 13362 consensus_queue.cc:237] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [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: "b873454109a6498ebb87844cb008f654" member_type: VOTER }
I20260812 06:16:45.290911 13363 sys_catalog.cc:455] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b873454109a6498ebb87844cb008f654" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b873454109a6498ebb87844cb008f654" member_type: VOTER } }
I20260812 06:16:45.290969 13364 sys_catalog.cc:455] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b873454109a6498ebb87844cb008f654. Latest consensus state: current_term: 1 leader_uuid: "b873454109a6498ebb87844cb008f654" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b873454109a6498ebb87844cb008f654" member_type: VOTER } }
I20260812 06:16:45.291060 13363 sys_catalog.cc:458] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:45.291146 13364 sys_catalog.cc:458] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:45.291677 13369 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:45.292591 13369 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:45.292761 12861 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:45.294560 13369 catalog_manager.cc:1383] Generated new cluster ID: 1a701ae815f14a57b2b860aec34b8c0a
I20260812 06:16:45.294623 13369 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:45.306643 13369 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:45.307216 13369 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:45.315842 13369 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654: Generated new TSK 0
I20260812 06:16:45.316017 13369 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:45.325042 12861 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:45.327098 13390 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:16:45.327098 13388 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:16:45.327180 12861 server_base.cc:1061] running on GCE node
W20260812 06:16:45.327253 13387 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:16:45.327538 12861 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:45.327581 12861 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:16:45.327597 12861 hybrid_clock.cc:648] HybridClock initialized: now 1786515405327597 us; error 0 us; skew 500 ppm
I20260812 06:16:45.328431 12861 webserver.cc:533] Webserver started at http://127.12.143.65:39263/ using document root <none> and password file <none>
I20260812 06:16:45.328616 12861 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:45.328686 12861 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:45.328764 12861 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:45.329187 12861 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/instance:
uuid: "061349abd65942c5818e4e373b9ed748"
format_stamp: "Formatted at 2026-08-12 06:16:45 on dist-test-slave-j2vl"
I20260812 06:16:45.330695 12861 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:45.331604 13401 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:16:45.331835 12861 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:45.331892 12861 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root
uuid: "061349abd65942c5818e4e373b9ed748"
format_stamp: "Formatted at 2026-08-12 06:16:45 on dist-test-slave-j2vl"
I20260812 06:16:45.331984 12861 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-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:16:45.341935 12861 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:45.342285 12861 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:45.342617 12861 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:45.343286 12861 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:45.343339 12861 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:45.343393 12861 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:45.343428 12861 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:45.348395 12861 rpc_server.cc:307] RPC server started. Bound to: 127.12.143.65:35257
I20260812 06:16:45.348449 13505 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.143.65:35257 every 8 connection(s)
I20260812 06:16:45.356312 13506 heartbeater.cc:344] Connected to a master server at 127.12.143.126:44297
I20260812 06:16:45.356453 13506 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:45.356720 13506 heartbeater.cc:507] Master 127.12.143.126:44297 requested a full tablet report, sending...
I20260812 06:16:45.357498 13282 ts_manager.cc:194] Registered new tserver with Master: 061349abd65942c5818e4e373b9ed748 (127.12.143.65:35257)
I20260812 06:16:45.357721 12861 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008900321s
I20260812 06:16:45.358376 13282 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37186
I20260812 06:16:45.365293 13282 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37192:
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:16:45.374697 13448 tablet_service.cc:1511] Processing CreateTablet for tablet 75913fad32154711ac68cc57c8e608dd (DEFAULT_TABLE table=heavy-update-compaction-test [id=44d2a0d1a5184511974f7189e9462b02]), partition=
I20260812 06:16:45.375029 13448 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 75913fad32154711ac68cc57c8e608dd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:45.377188 13528 tablet_bootstrap.cc:492] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Bootstrap starting.
I20260812 06:16:45.378090 13528 tablet_bootstrap.cc:654] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:45.379120 13528 tablet_bootstrap.cc:492] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: No bootstrap required, opened a new log
I20260812 06:16:45.379218 13528 ts_tablet_manager.cc:1403] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:45.379738 13528 raft_consensus.cc:359] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "061349abd65942c5818e4e373b9ed748" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 35257 } }
I20260812 06:16:45.379832 13528 raft_consensus.cc:385] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:45.379890 13528 raft_consensus.cc:740] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 061349abd65942c5818e4e373b9ed748, State: Initialized, Role: FOLLOWER
I20260812 06:16:45.380062 13528 consensus_queue.cc:260] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [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: "061349abd65942c5818e4e373b9ed748" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 35257 } }
I20260812 06:16:45.380167 13528 raft_consensus.cc:399] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:45.380223 13528 raft_consensus.cc:493] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:45.380285 13528 raft_consensus.cc:3060] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:45.380985 13528 raft_consensus.cc:515] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "061349abd65942c5818e4e373b9ed748" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 35257 } }
I20260812 06:16:45.381102 13528 leader_election.cc:304] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [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: 061349abd65942c5818e4e373b9ed748; no voters: 
I20260812 06:16:45.381363 13528 leader_election.cc:290] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:45.381549 13531 raft_consensus.cc:2804] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:45.381726 13528 ts_tablet_manager.cc:1434] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:45.381783 13506 heartbeater.cc:499] Master 127.12.143.126:44297 was elected leader, sending a full tablet report...
I20260812 06:16:45.381783 13531 raft_consensus.cc:697] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 1 LEADER]: Becoming Leader. State: Replica: 061349abd65942c5818e4e373b9ed748, State: Running, Role: LEADER
I20260812 06:16:45.381945 13531 consensus_queue.cc:237] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [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: "061349abd65942c5818e4e373b9ed748" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 35257 } }
I20260812 06:16:45.383370 13282 catalog_manager.cc:5719] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 reported cstate change: term changed from 0 to 1, leader changed from <none> to 061349abd65942c5818e4e373b9ed748 (127.12.143.65). New cstate: current_term: 1 leader_uuid: "061349abd65942c5818e4e373b9ed748" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "061349abd65942c5818e4e373b9ed748" member_type: VOTER last_known_addr { host: "127.12.143.65" port: 35257 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:45.442075 12861 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:16:45.599289 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushMRSOp(75913fad32154711ac68cc57c8e608dd): perf score=19.054940
I20260812 06:16:45.752574 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushMRSOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.153s	user 0.130s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1129,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39067,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:16:45.753324 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling LogGCOp(75913fad32154711ac68cc57c8e608dd): free 20743880 bytes of WAL
I20260812 06:16:45.753620 13408 log_reader.cc:385] T 75913fad32154711ac68cc57c8e608dd: removed 2 log segments from log reader
I20260812 06:16:45.753677 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000001 (ops 1-6)
I20260812 06:16:45.753708 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000002 (ops 7-11)
I20260812 06:16:45.757982 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: LogGCOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:16:45.758352 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:45.779516 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.021s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5067,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.779918 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:45.789778 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.790149 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd): perf score=1.000000
I20260812 06:16:45.940346 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.150s	user 0.094s	sys 0.055s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405548,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":543,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27215,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":369,"threads_started":5,"update_count":2450}
I20260812 06:16:45.941026 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling UndoDeltaBlockGCOp(75913fad32154711ac68cc57c8e608dd): 16821650 bytes on disk
I20260812 06:16:45.941485 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: UndoDeltaBlockGCOp(75913fad32154711ac68cc57c8e608dd) 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:16:45.941985 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:45.980446 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.038s	user 0.032s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16668,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.982074 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:45.995642 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.996061 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd): perf score=1.000000
I20260812 06:16:46.128520 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.132s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1422,"lbm_read_time_us":8979,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24293,"lbm_writes_lt_1ms":443,"mutex_wait_us":287,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:46.129221 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=11.118625
I20260812 06:16:46.173261 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.044s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15079,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:46.173837 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:46.189365 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.190099 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd): perf score=1.000000
I20260812 06:16:46.442498 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.252s	user 0.113s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":98,"lbm_read_time_us":9958,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23448,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:16:46.443744 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=22.032687
I20260812 06:16:46.551882 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.108s	user 0.042s	sys 0.032s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":29924,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:16:46.552433 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:46.636631 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.084s	user 0.022s	sys 0.000s Metrics: {"bytes_written":8205081,"delete_count":0,"lbm_write_time_us":9760,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.637173 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:46.740803 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.103s	user 0.021s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11144,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.741549 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:46.841509 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.100s	user 0.020s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13356,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:46.842135 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:46.938474 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.096s	user 0.020s	sys 0.006s Metrics: {"bytes_written":9271705,"delete_count":0,"lbm_write_time_us":10852,"lbm_writes_lt_1ms":229,"reinsert_count":0,"update_count":1130}
I20260812 06:16:46.939060 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=9.134250
I20260812 06:16:47.042557 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.103s	user 0.019s	sys 0.009s Metrics: {"bytes_written":10830632,"delete_count":0,"lbm_write_time_us":12241,"lbm_writes_lt_1ms":267,"reinsert_count":0,"update_count":1320}
I20260812 06:16:47.043576 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:47.148207 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.104s	user 0.016s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9420,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1000}
I20260812 06:16:47.148895 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:47.254885 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.106s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:47.255928 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:47.355971 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.100s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8873,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:47.356525 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:47.456002 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.099s	user 0.020s	sys 0.016s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":16256,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:47.456722 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:47.556455 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.100s	user 0.014s	sys 0.011s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11568,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.557197 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:47.659783 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.102s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8676,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:47.660619 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:47.763320 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.103s	user 0.022s	sys 0.012s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":15037,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:47.764138 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:47.870150 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.106s	user 0.015s	sys 0.011s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9705,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.870729 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:47.972177 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.101s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14621,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:47.972947 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:48.068550 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.095s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8734,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.069334 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:48.170527 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.101s	user 0.024s	sys 0.005s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12669,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:48.171187 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=9.134250
I20260812 06:16:48.272140 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.101s	user 0.025s	sys 0.004s Metrics: {"bytes_written":10871650,"delete_count":0,"lbm_write_time_us":13061,"lbm_writes_lt_1ms":268,"reinsert_count":0,"update_count":1325}
I20260812 06:16:48.272753 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:48.375926 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.103s	user 0.026s	sys 0.004s Metrics: {"bytes_written":9230686,"delete_count":0,"lbm_write_time_us":12590,"lbm_writes_lt_1ms":228,"reinsert_count":0,"update_count":1125}
I20260812 06:16:48.376909 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:48.478014 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.101s	user 0.017s	sys 0.012s Metrics: {"bytes_written":8410201,"delete_count":0,"lbm_write_time_us":13048,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:16:48.478935 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:48.581019 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.102s	user 0.003s	sys 0.016s Metrics: {"bytes_written":8410202,"delete_count":0,"lbm_write_time_us":9275,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:16:48.582005 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:48.683032 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.101s	user 0.019s	sys 0.013s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":14705,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:48.683959 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:48.784529 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.100s	user 0.020s	sys 0.000s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9694,"lbm_writes_lt_1ms":213,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1050}
I20260812 06:16:48.785127 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=10.126437
I20260812 06:16:48.880700 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.095s	user 0.023s	sys 0.009s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":15285,"lbm_writes_lt_1ms":293,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":1450}
I20260812 06:16:48.881325 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:48.980245 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.099s	user 0.015s	sys 0.009s Metrics: {"bytes_written":7753813,"delete_count":0,"lbm_write_time_us":11477,"lbm_writes_lt_1ms":192,"reinsert_count":0,"update_count":945}
I20260812 06:16:48.980916 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=7.149875
I20260812 06:16:49.019341 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.038s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8656350,"delete_count":0,"lbm_write_time_us":11235,"lbm_writes_lt_1ms":214,"reinsert_count":0,"update_count":1055}
I20260812 06:16:49.019840 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:49.034657 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.035302 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushMRSOp(75913fad32154711ac68cc57c8e608dd): perf score=1.195565
I20260812 06:16:49.072412 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushMRSOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":3160657,"cfile_init":1,"dirs.queue_time_us":186,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1333,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3260,"lbm_writes_lt_1ms":49,"peak_mem_usage":0,"rows_written":77,"thread_start_us":77,"threads_started":1}
I20260812 06:16:49.073053 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling LogGCOp(75913fad32154711ac68cc57c8e608dd): free 320090228 bytes of WAL
I20260812 06:16:49.073321 13408 log_reader.cc:385] T 75913fad32154711ac68cc57c8e608dd: removed 32 log segments from log reader
I20260812 06:16:49.073422 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000003 (ops 12-16)
I20260812 06:16:49.073477 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000004 (ops 17-21)
I20260812 06:16:49.073534 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000005 (ops 22-26)
I20260812 06:16:49.073580 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000006 (ops 27-30)
I20260812 06:16:49.073621 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000007 (ops 31-35)
I20260812 06:16:49.073658 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000008 (ops 36-40)
I20260812 06:16:49.073697 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000009 (ops 41-44)
I20260812 06:16:49.073737 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000010 (ops 45-49)
I20260812 06:16:49.073776 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000011 (ops 50-54)
I20260812 06:16:49.073815 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000012 (ops 55-59)
I20260812 06:16:49.073854 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000013 (ops 60-64)
I20260812 06:16:49.073945 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000014 (ops 65-68)
I20260812 06:16:49.073992 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000015 (ops 69-73)
I20260812 06:16:49.074031 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000016 (ops 74-78)
I20260812 06:16:49.074070 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000017 (ops 79-82)
I20260812 06:16:49.074110 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000018 (ops 83-87)
I20260812 06:16:49.074147 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000019 (ops 88-92)
I20260812 06:16:49.074186 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000020 (ops 93-97)
I20260812 06:16:49.074224 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000021 (ops 98-102)
I20260812 06:16:49.074262 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000022 (ops 103-106)
I20260812 06:16:49.074301 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000023 (ops 107-111)
I20260812 06:16:49.074339 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000024 (ops 112-116)
I20260812 06:16:49.074374 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000025 (ops 117-121)
I20260812 06:16:49.074406 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000026 (ops 122-126)
I20260812 06:16:49.074443 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000027 (ops 127-131)
I20260812 06:16:49.074481 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000028 (ops 132-136)
I20260812 06:16:49.074522 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000029 (ops 137-141)
I20260812 06:16:49.074560 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000030 (ops 142-146)
I20260812 06:16:49.074599 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000031 (ops 147-150)
I20260812 06:16:49.074638 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000032 (ops 151-155)
I20260812 06:16:49.074677 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000033 (ops 156-160)
I20260812 06:16:49.074716 13408 log.cc:1079] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: Deleting log segment in path: /tmp/dist-test-taskL4VNxk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515399859850-12861-0/minicluster-data/ts-0-root/wals/75913fad32154711ac68cc57c8e608dd/wal-000000034 (ops 161-165)
I20260812 06:16:49.147051 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: LogGCOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.074s	user 0.005s	sys 0.067s Metrics: {}
I20260812 06:16:49.147475 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=6.157687
I20260812 06:16:49.174045 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.026s	user 0.015s	sys 0.009s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10378,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:49.174506 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd): perf score=2.188937
I20260812 06:16:49.184376 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: FlushDeltaMemStoresOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.184769 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling UndoDeltaBlockGCOp(75913fad32154711ac68cc57c8e608dd): 1003 bytes on disk
I20260812 06:16:49.185144 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: UndoDeltaBlockGCOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:49.185628 13511 maintenance_manager.cc:419] P 061349abd65942c5818e4e373b9ed748: Scheduling MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd): perf score=1.000000
I20260812 06:16:50.099354 12861 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.657s	user 1.726s	sys 0.132s
W20260812 06:16:50.864413 12861 scanner-internal.cc:458] Time spent opening tablet: real 0.765s	user 0.000s	sys 0.000s
I20260812 06:16:50.866632 12861 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.767s	user 0.001s	sys 0.000s
I20260812 06:16:50.867161 12861 tablet_server.cc:179] TabletServer@127.12.143.65:0 shutting down...
I20260812 06:16:50.949903 13408 maintenance_manager.cc:643] P 061349abd65942c5818e4e373b9ed748: MajorDeltaCompactionOp(75913fad32154711ac68cc57c8e608dd) complete. Timing: real 1.764s	user 1.057s	sys 0.688s Metrics: {"cfile_cache_miss":6859,"cfile_cache_miss_bytes":283270931,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":29,"delta_iterators_relevant":29,"dirs.queue_time_us":940,"lbm_read_time_us":111298,"lbm_reads_lt_1ms":6895,"lbm_write_time_us":308117,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":6847,"peak_mem_usage":845989936,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":423,"threads_started":7,"update_count":34000}
I20260812 06:16:50.950660 12861 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:50.950954 12861 tablet_replica.cc:333] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748: stopping tablet replica
I20260812 06:16:50.951128 12861 raft_consensus.cc:2243] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:50.951299 12861 raft_consensus.cc:2272] T 75913fad32154711ac68cc57c8e608dd P 061349abd65942c5818e4e373b9ed748 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:50.975181 12861 tablet_server.cc:196] TabletServer@127.12.143.65:0 shutdown complete.
I20260812 06:16:52.033887 12861 master.cc:562] Master@127.12.143.126:44297 shutting down...
I20260812 06:16:52.037981 12861 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:52.038149 12861 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:52.038219 12861 tablet_replica.cc:333] T 00000000000000000000000000000000 P b873454109a6498ebb87844cb008f654: stopping tablet replica
I20260812 06:16:52.050654 12861 master.cc:584] Master@127.12.143.126:44297 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6904 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12274 ms total)

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