[==========] 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:20:19.372716 21008 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.132.62:46809
I20260812 06:20:19.373878 21008 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:20:19.374536 21008 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.381126 21022 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:20:19.381163 21018 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:20:19.381299 21008 server_base.cc:1061] running on GCE node
W20260812 06:20:19.381500 21019 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:20:19.382050 21008 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.382192 21008 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:20:19.382256 21008 hybrid_clock.cc:648] HybridClock initialized: now 1786515619382252 us; error 0 us; skew 500 ppm
I20260812 06:20:19.384568 21008 webserver.cc:533] Webserver started at http://127.20.132.62:42527/ using document root <none> and password file <none>
I20260812 06:20:19.385214 21008 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.385299 21008 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.385548 21008 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.387221 21008 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/master-0-root/instance:
uuid: "b0eb0bb1c2dc472b902a433661c018d3"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-zh2d"
I20260812 06:20:19.390789 21008 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:20:19.393137 21028 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:20:19.394192 21008 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:19.394338 21008 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/master-0-root
uuid: "b0eb0bb1c2dc472b902a433661c018d3"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-zh2d"
I20260812 06:20:19.394452 21008 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-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:20:19.409298 21008 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.409893 21008 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:20:19.410082 21008 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.418244 21008 rpc_server.cc:307] RPC server started. Bound to: 127.20.132.62:46809
I20260812 06:20:19.418263 21122 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.132.62:46809 every 8 connection(s)
I20260812 06:20:19.420828 21123 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:20:19.426720 21123 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: Bootstrap starting.
I20260812 06:20:19.429353 21123 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.430343 21123 log.cc:826] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:19.432278 21123 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: No bootstrap required, opened a new log
I20260812 06:20:19.435388 21123 raft_consensus.cc:359] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER }
I20260812 06:20:19.435588 21123 raft_consensus.cc:385] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.435636 21123 raft_consensus.cc:740] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b0eb0bb1c2dc472b902a433661c018d3, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.436270 21123 consensus_queue.cc:260] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [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: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER }
I20260812 06:20:19.436412 21123 raft_consensus.cc:399] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.436461 21123 raft_consensus.cc:493] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.436556 21123 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.437431 21123 raft_consensus.cc:515] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER }
I20260812 06:20:19.437861 21123 leader_election.cc:304] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [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: b0eb0bb1c2dc472b902a433661c018d3; no voters: 
I20260812 06:20:19.438171 21123 leader_election.cc:290] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.438301 21129 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.438580 21129 raft_consensus.cc:697] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 1 LEADER]: Becoming Leader. State: Replica: b0eb0bb1c2dc472b902a433661c018d3, State: Running, Role: LEADER
I20260812 06:20:19.439056 21129 consensus_queue.cc:237] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [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: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER }
I20260812 06:20:19.439363 21123 sys_catalog.cc:565] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.441206 21132 sys_catalog.cc:455] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b0eb0bb1c2dc472b902a433661c018d3. Latest consensus state: current_term: 1 leader_uuid: "b0eb0bb1c2dc472b902a433661c018d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER } }
I20260812 06:20:19.441354 21132 sys_catalog.cc:458] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.441239 21131 sys_catalog.cc:455] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b0eb0bb1c2dc472b902a433661c018d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0eb0bb1c2dc472b902a433661c018d3" member_type: VOTER } }
I20260812 06:20:19.441622 21131 sys_catalog.cc:458] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.441818 21008 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.441817 21153 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.444208 21153 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.449059 21153 catalog_manager.cc:1383] Generated new cluster ID: cbdfc10427784c3faf674178466a4c3e
I20260812 06:20:19.449131 21153 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.493444 21153 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.494400 21153 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.500646 21153 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: Generated new TSK 0
I20260812 06:20:19.501367 21153 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.506727 21008 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.510030 21161 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:20:19.510032 21162 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:20:19.510146 21008 server_base.cc:1061] running on GCE node
W20260812 06:20:19.510252 21165 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:20:19.510468 21008 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.510525 21008 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:20:19.510541 21008 hybrid_clock.cc:648] HybridClock initialized: now 1786515619510542 us; error 0 us; skew 500 ppm
I20260812 06:20:19.511713 21008 webserver.cc:533] Webserver started at http://127.20.132.1:38353/ using document root <none> and password file <none>
I20260812 06:20:19.511924 21008 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.511986 21008 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.512106 21008 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.512552 21008 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/instance:
uuid: "edce54172e8d4df3af5dd846d1c5b754"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-zh2d"
I20260812 06:20:19.514326 21008 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.515467 21173 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:20:19.515772 21008 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.515849 21008 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root
uuid: "edce54172e8d4df3af5dd846d1c5b754"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-zh2d"
I20260812 06:20:19.515949 21008 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-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:20:19.522444 21008 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.522882 21008 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.523470 21008 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.524407 21008 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.524466 21008 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.524544 21008 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.524585 21008 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.532639 21008 rpc_server.cc:307] RPC server started. Bound to: 127.20.132.1:36071
I20260812 06:20:19.532701 21285 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.132.1:36071 every 8 connection(s)
I20260812 06:20:19.543717 21287 heartbeater.cc:344] Connected to a master server at 127.20.132.62:46809
I20260812 06:20:19.544003 21287 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.544452 21287 heartbeater.cc:507] Master 127.20.132.62:46809 requested a full tablet report, sending...
I20260812 06:20:19.546013 21054 ts_manager.cc:194] Registered new tserver with Master: edce54172e8d4df3af5dd846d1c5b754 (127.20.132.1:36071)
I20260812 06:20:19.546267 21008 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012837269s
I20260812 06:20:19.547261 21054 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46088
I20260812 06:20:19.555766 21054 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46104:
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:20:19.571376 21220 tablet_service.cc:1511] Processing CreateTablet for tablet 2fd8df7a46a849c9858a856ae729b10c (DEFAULT_TABLE table=heavy-update-compaction-test [id=bf134e02073e4b60a71bd552f211b617]), partition=
I20260812 06:20:19.571875 21220 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2fd8df7a46a849c9858a856ae729b10c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.574353 21303 tablet_bootstrap.cc:492] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Bootstrap starting.
I20260812 06:20:19.575599 21303 tablet_bootstrap.cc:654] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.577064 21303 tablet_bootstrap.cc:492] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: No bootstrap required, opened a new log
I20260812 06:20:19.577178 21303 ts_tablet_manager.cc:1403] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.577745 21303 raft_consensus.cc:359] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edce54172e8d4df3af5dd846d1c5b754" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 36071 } }
I20260812 06:20:19.577883 21303 raft_consensus.cc:385] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.577921 21303 raft_consensus.cc:740] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: edce54172e8d4df3af5dd846d1c5b754, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.578073 21303 consensus_queue.cc:260] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [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: "edce54172e8d4df3af5dd846d1c5b754" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 36071 } }
I20260812 06:20:19.578219 21303 raft_consensus.cc:399] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.578320 21303 raft_consensus.cc:493] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.578385 21303 raft_consensus.cc:3060] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.579463 21303 raft_consensus.cc:515] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edce54172e8d4df3af5dd846d1c5b754" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 36071 } }
I20260812 06:20:19.579640 21303 leader_election.cc:304] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [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: edce54172e8d4df3af5dd846d1c5b754; no voters: 
I20260812 06:20:19.579850 21303 leader_election.cc:290] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.579982 21306 raft_consensus.cc:2804] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.580226 21303 ts_tablet_manager.cc:1434] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.580467 21287 heartbeater.cc:499] Master 127.20.132.62:46809 was elected leader, sending a full tablet report...
I20260812 06:20:19.580257 21306 raft_consensus.cc:697] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 1 LEADER]: Becoming Leader. State: Replica: edce54172e8d4df3af5dd846d1c5b754, State: Running, Role: LEADER
I20260812 06:20:19.580938 21306 consensus_queue.cc:237] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [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: "edce54172e8d4df3af5dd846d1c5b754" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 36071 } }
I20260812 06:20:19.584384 21054 catalog_manager.cc:5719] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 reported cstate change: term changed from 0 to 1, leader changed from <none> to edce54172e8d4df3af5dd846d1c5b754 (127.20.132.1). New cstate: current_term: 1 leader_uuid: "edce54172e8d4df3af5dd846d1c5b754" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edce54172e8d4df3af5dd846d1c5b754" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 36071 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.654443 21008 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.016s	sys 0.010s
I20260812 06:20:19.783927 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c): perf score=15.086190
I20260812 06:20:19.934631 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.150s	user 0.121s	sys 0.028s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":236,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":898,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36740,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":116,"threads_started":1,"update_count":1000}
I20260812 06:20:19.935771 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling LogGCOp(2fd8df7a46a849c9858a856ae729b10c): free 20743880 bytes of WAL
I20260812 06:20:19.936100 21183 log_reader.cc:385] T 2fd8df7a46a849c9858a856ae729b10c: removed 2 log segments from log reader
I20260812 06:20:19.936182 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000001 (ops 1-6)
I20260812 06:20:19.936256 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000002 (ops 7-11)
I20260812 06:20:19.941408 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: LogGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:19.941902 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:19.971444 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.029s	user 0.010s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7014,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.971908 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c): 12719216 bytes on disk
I20260812 06:20:19.972539 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.973003 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:19.988088 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.988674 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:20.139958 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.151s	user 0.117s	sys 0.026s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20262142,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":950,"lbm_read_time_us":9451,"lbm_reads_lt_1ms":459,"lbm_write_time_us":29188,"lbm_writes_lt_1ms":433,"mutex_wait_us":26,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":319,"threads_started":5,"update_count":1950}
I20260812 06:20:20.140560 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:20.189229 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.048s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16512,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.189697 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:20.201582 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.202225 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:20.334543 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.132s	user 0.108s	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":923,"lbm_read_time_us":9099,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26500,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":58752,"update_count":2000}
I20260812 06:20:20.335297 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:20.390064 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.055s	user 0.042s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19562,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.390702 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:20.408308 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.408972 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:20.568060 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.159s	user 0.123s	sys 0.033s 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":626,"lbm_read_time_us":13698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26155,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:20:20.568766 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:20.616708 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.048s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18748,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.617306 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:20.633833 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.634469 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:20.775105 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.140s	user 0.120s	sys 0.019s 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":177,"lbm_read_time_us":10040,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29728,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:20.775952 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:20.822134 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.046s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16004,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.822593 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:20.833721 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.834522 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:20.964058 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.129s	user 0.101s	sys 0.028s 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":675,"lbm_read_time_us":8885,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28405,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":86016,"update_count":2000}
I20260812 06:20:20.964706 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:21.015463 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.051s	user 0.016s	sys 0.029s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.015998 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:21.027477 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.028085 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:21.157408 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.129s	user 0.098s	sys 0.030s 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":1446,"lbm_read_time_us":9990,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27380,"lbm_writes_lt_1ms":443,"mutex_wait_us":381,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2000}
I20260812 06:20:21.158100 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:21.215607 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.057s	user 0.036s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18060,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.216114 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:21.227265 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.227771 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:21.387660 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.160s	user 0.114s	sys 0.043s 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":166,"lbm_read_time_us":12491,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27753,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:20:21.388162 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:21.434762 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.046s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17453,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.435318 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:21.447520 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.448261 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:21.482079 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1230,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1790,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:21.482910 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling LogGCOp(2fd8df7a46a849c9858a856ae729b10c): free 124710292 bytes of WAL
I20260812 06:20:21.483167 21183 log_reader.cc:385] T 2fd8df7a46a849c9858a856ae729b10c: removed 12 log segments from log reader
I20260812 06:20:21.483211 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000003 (ops 12-16)
I20260812 06:20:21.483264 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000004 (ops 17-21)
I20260812 06:20:21.483311 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000005 (ops 22-26)
I20260812 06:20:21.483354 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000006 (ops 27-31)
I20260812 06:20:21.483400 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000007 (ops 32-36)
I20260812 06:20:21.483456 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000008 (ops 37-41)
I20260812 06:20:21.483508 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000009 (ops 42-46)
I20260812 06:20:21.483546 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000010 (ops 47-51)
I20260812 06:20:21.483587 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000011 (ops 52-56)
I20260812 06:20:21.483624 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000012 (ops 57-61)
I20260812 06:20:21.483662 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000013 (ops 62-66)
I20260812 06:20:21.483701 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000014 (ops 67-71)
I20260812 06:20:21.512997 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: LogGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:21.513499 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=3.181125
I20260812 06:20:21.541147 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.027s	user 0.010s	sys 0.017s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7457,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.541704 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:21.551864 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4040,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.552309 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:21.757468 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.205s	user 0.139s	sys 0.065s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":724,"lbm_read_time_us":15191,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36889,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25344,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:21.758260 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c): 482 bytes on disk
I20260812 06:20:21.758831 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.759549 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:21.797407 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15028,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.797962 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:21.812892 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.015s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.813560 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:21.977826 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.164s	user 0.098s	sys 0.059s 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":281,"lbm_read_time_us":10904,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27507,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.978456 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=10.126437
I20260812 06:20:22.025213 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.047s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.025733 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:22.037328 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.038189 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:22.195972 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.157s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":11319,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29889,"lbm_writes_lt_1ms":443,"mutex_wait_us":351,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:20:22.196653 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=11.118625
I20260812 06:20:22.236070 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.039s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16654,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.236631 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:22.260484 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.024s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4865,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.261020 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:22.271746 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.272169 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:22.444546 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.172s	user 0.129s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":314,"lbm_read_time_us":11448,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30836,"lbm_writes_lt_1ms":543,"mutex_wait_us":400,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:22.445163 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:22.514040 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.069s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25748,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.514532 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:22.525678 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.526175 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:22.718231 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.192s	user 0.123s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":724,"lbm_read_time_us":14056,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32070,"lbm_writes_lt_1ms":543,"mutex_wait_us":335,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":53248,"update_count":2500}
I20260812 06:20:22.719022 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:22.783062 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.064s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21916,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.783624 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:22.794914 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.795504 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:22.983784 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.188s	user 0.138s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":772,"lbm_read_time_us":13722,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34395,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:20:22.984457 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=11.118625
I20260812 06:20:23.022439 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.038s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17164,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.023059 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:23.043321 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6723,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.043821 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:23.075112 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1404,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:23.075912 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling LogGCOp(2fd8df7a46a849c9858a856ae729b10c): free 120100330 bytes of WAL
I20260812 06:20:23.076162 21183 log_reader.cc:385] T 2fd8df7a46a849c9858a856ae729b10c: removed 12 log segments from log reader
I20260812 06:20:23.076206 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000015 (ops 72-76)
I20260812 06:20:23.076258 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000016 (ops 77-81)
I20260812 06:20:23.076304 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000017 (ops 82-86)
I20260812 06:20:23.076351 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000018 (ops 87-91)
I20260812 06:20:23.076390 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000019 (ops 92-96)
I20260812 06:20:23.076435 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000020 (ops 97-100)
I20260812 06:20:23.076486 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000021 (ops 101-105)
I20260812 06:20:23.076514 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000022 (ops 106-110)
I20260812 06:20:23.076555 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000023 (ops 111-114)
I20260812 06:20:23.076597 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000024 (ops 115-119)
I20260812 06:20:23.076637 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000025 (ops 120-124)
I20260812 06:20:23.076675 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000026 (ops 125-128)
I20260812 06:20:23.104956 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: LogGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:23.105497 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=3.181125
I20260812 06:20:23.128507 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.023s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7492,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.129063 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c): 461 bytes on disk
I20260812 06:20:23.129586 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.130131 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:23.144760 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5492,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.145366 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:23.373708 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.228s	user 0.148s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877318,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3904,"lbm_read_time_us":16563,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37825,"lbm_writes_lt_1ms":643,"mutex_wait_us":3539,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":107,"threads_started":1,"update_count":3000}
I20260812 06:20:23.375165 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:23.436765 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.061s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":27458,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.437641 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:23.454311 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.016s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.454907 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:23.636094 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.181s	user 0.116s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":13246,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31154,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:20:23.636956 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:23.697299 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.060s	user 0.052s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27045,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.697832 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:23.710740 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.711248 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:23.908934 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.197s	user 0.161s	sys 0.035s 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":786,"lbm_read_time_us":14945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38645,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":79360,"update_count":2500}
I20260812 06:20:23.909724 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:23.967336 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.057s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21013,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.967921 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:23.978956 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.979413 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:24.172675 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.193s	user 0.144s	sys 0.040s 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":1055,"lbm_read_time_us":14328,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32180,"lbm_writes_lt_1ms":543,"mutex_wait_us":354,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:20:24.173328 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:24.238502 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.065s	user 0.036s	sys 0.018s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":19696,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.239075 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:24.250721 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.251233 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:24.450409 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.199s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":13645,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32987,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:24.451177 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:24.507315 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.056s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23379,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.507843 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:24.520565 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.013s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.521150 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:24.719122 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.198s	user 0.124s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":12702,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33028,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2500}
I20260812 06:20:24.719739 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=14.095187
I20260812 06:20:24.773047 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.053s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20673,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.773541 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:24.786158 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.786862 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:24.820187 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushMRSOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2155,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:24.821089 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling LogGCOp(2fd8df7a46a849c9858a856ae729b10c): free 133024644 bytes of WAL
I20260812 06:20:24.821362 21183 log_reader.cc:385] T 2fd8df7a46a849c9858a856ae729b10c: removed 13 log segments from log reader
I20260812 06:20:24.821429 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000027 (ops 129-133)
I20260812 06:20:24.821466 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000028 (ops 134-138)
I20260812 06:20:24.821501 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000029 (ops 139-143)
I20260812 06:20:24.821537 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000030 (ops 144-148)
I20260812 06:20:24.821563 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000031 (ops 149-153)
I20260812 06:20:24.821592 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000032 (ops 154-158)
I20260812 06:20:24.821621 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000033 (ops 159-163)
I20260812 06:20:24.821650 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000034 (ops 164-168)
I20260812 06:20:24.821682 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000035 (ops 169-173)
I20260812 06:20:24.821715 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000036 (ops 174-178)
I20260812 06:20:24.821749 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000037 (ops 179-183)
I20260812 06:20:24.821779 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000038 (ops 184-188)
I20260812 06:20:24.821810 21183 log.cc:1079] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/2fd8df7a46a849c9858a856ae729b10c/wal-000000039 (ops 189-192)
I20260812 06:20:24.858731 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: LogGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.037s	user 0.000s	sys 0.036s Metrics: {}
I20260812 06:20:24.861287 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c): 493 bytes on disk
I20260812 06:20:24.861800 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: UndoDeltaBlockGCOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.862443 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:24.881811 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.019s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.882350 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c): perf score=2.188937
I20260812 06:20:24.898665 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: FlushDeltaMemStoresOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.899271 21288 maintenance_manager.cc:419] P edce54172e8d4df3af5dd846d1c5b754: Scheduling MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c): perf score=1.000000
I20260812 06:20:24.993346 21008 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.339s	user 1.875s	sys 0.230s
I20260812 06:20:25.103991 21008 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.110s	user 0.001s	sys 0.000s
I20260812 06:20:25.104707 21008 tablet_server.cc:179] TabletServer@127.20.132.1:0 shutting down...
I20260812 06:20:25.123628 21183 maintenance_manager.cc:643] P edce54172e8d4df3af5dd846d1c5b754: MajorDeltaCompactionOp(2fd8df7a46a849c9858a856ae729b10c) complete. Timing: real 0.224s	user 0.162s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3855,"lbm_read_time_us":15923,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37459,"lbm_writes_lt_1ms":743,"mutex_wait_us":1721,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:20:25.124361 21008 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:25.124891 21008 tablet_replica.cc:333] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754: stopping tablet replica
I20260812 06:20:25.125226 21008 raft_consensus.cc:2243] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.125535 21008 raft_consensus.cc:2272] T 2fd8df7a46a849c9858a856ae729b10c P edce54172e8d4df3af5dd846d1c5b754 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.142298 21008 tablet_server.cc:196] TabletServer@127.20.132.1:0 shutdown complete.
I20260812 06:20:25.181945 21008 master.cc:562] Master@127.20.132.62:46809 shutting down...
I20260812 06:20:25.185396 21008 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.185570 21008 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.185626 21008 tablet_replica.cc:333] T 00000000000000000000000000000000 P b0eb0bb1c2dc472b902a433661c018d3: stopping tablet replica
I20260812 06:20:25.197968 21008 master.cc:584] Master@127.20.132.62:46809 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5918 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:25.306357 21008 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.132.62:37825
I20260812 06:20:25.306774 21008 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.309224 21344 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:20:25.309340 21345 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:20:25.309422 21008 server_base.cc:1061] running on GCE node
W20260812 06:20:25.309348 21347 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:20:25.309609 21008 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.309650 21008 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:20:25.309666 21008 hybrid_clock.cc:648] HybridClock initialized: now 1786515625309666 us; error 0 us; skew 500 ppm
I20260812 06:20:25.310518 21008 webserver.cc:533] Webserver started at http://127.20.132.62:37813/ using document root <none> and password file <none>
I20260812 06:20:25.310655 21008 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.310693 21008 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.310745 21008 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.311084 21008 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/master-0-root/instance:
uuid: "2e4b86b2c7824f5e86d229061e59fb83"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-zh2d"
I20260812 06:20:25.312646 21008 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:25.314409 21356 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:20:25.314682 21008 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.314749 21008 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/master-0-root
uuid: "2e4b86b2c7824f5e86d229061e59fb83"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-zh2d"
I20260812 06:20:25.314848 21008 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-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:20:25.321143 21008 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.321488 21008 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.325852 21008 rpc_server.cc:307] RPC server started. Bound to: 127.20.132.62:37825
I20260812 06:20:25.331321 21440 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:20:25.331907 21439 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.132.62:37825 every 8 connection(s)
I20260812 06:20:25.333525 21440 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83: Bootstrap starting.
I20260812 06:20:25.334326 21440 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.335388 21440 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83: No bootstrap required, opened a new log
I20260812 06:20:25.335795 21440 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER }
I20260812 06:20:25.335884 21440 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.335944 21440 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2e4b86b2c7824f5e86d229061e59fb83, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.336124 21440 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [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: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER }
I20260812 06:20:25.336197 21440 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.336264 21440 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.336330 21440 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.337049 21440 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER }
I20260812 06:20:25.337198 21440 leader_election.cc:304] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [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: 2e4b86b2c7824f5e86d229061e59fb83; no voters: 
I20260812 06:20:25.337409 21440 leader_election.cc:290] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.337553 21447 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.337793 21447 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 1 LEADER]: Becoming Leader. State: Replica: 2e4b86b2c7824f5e86d229061e59fb83, State: Running, Role: LEADER
I20260812 06:20:25.337920 21440 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.337934 21447 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [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: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER }
I20260812 06:20:25.338452 21448 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2e4b86b2c7824f5e86d229061e59fb83" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER } }
I20260812 06:20:25.338482 21451 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2e4b86b2c7824f5e86d229061e59fb83. Latest consensus state: current_term: 1 leader_uuid: "2e4b86b2c7824f5e86d229061e59fb83" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e4b86b2c7824f5e86d229061e59fb83" member_type: VOTER } }
I20260812 06:20:25.338632 21451 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.338616 21448 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.339382 21460 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.340077 21460 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.340325 21008 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:25.341984 21460 catalog_manager.cc:1383] Generated new cluster ID: 939a25f56f824e9ebe506284a4446e6e
I20260812 06:20:25.342043 21460 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.350574 21460 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.351109 21460 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.361073 21460 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83: Generated new TSK 0
I20260812 06:20:25.361258 21460 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.372753 21008 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.374797 21483 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:20:25.374797 21481 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:20:25.374996 21008 server_base.cc:1061] running on GCE node
W20260812 06:20:25.374930 21486 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:20:25.375314 21008 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.375386 21008 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:20:25.375422 21008 hybrid_clock.cc:648] HybridClock initialized: now 1786515625375421 us; error 0 us; skew 500 ppm
I20260812 06:20:25.376309 21008 webserver.cc:533] Webserver started at http://127.20.132.1:38845/ using document root <none> and password file <none>
I20260812 06:20:25.376519 21008 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.376585 21008 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.376682 21008 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.377197 21008 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/instance:
uuid: "e32cf383d6b8428d97cf52c05c036221"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-zh2d"
I20260812 06:20:25.379460 21008 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:25.381062 21495 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:20:25.381361 21008 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.381462 21008 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root
uuid: "e32cf383d6b8428d97cf52c05c036221"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-zh2d"
I20260812 06:20:25.381547 21008 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-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:20:25.392920 21008 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.393299 21008 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.393611 21008 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.394085 21008 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.394150 21008 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.394207 21008 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.394258 21008 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.399056 21008 rpc_server.cc:307] RPC server started. Bound to: 127.20.132.1:39487
I20260812 06:20:25.401300 21605 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.132.1:39487 every 8 connection(s)
I20260812 06:20:25.410885 21606 heartbeater.cc:344] Connected to a master server at 127.20.132.62:37825
I20260812 06:20:25.411021 21606 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.411253 21606 heartbeater.cc:507] Master 127.20.132.62:37825 requested a full tablet report, sending...
I20260812 06:20:25.411966 21385 ts_manager.cc:194] Registered new tserver with Master: e32cf383d6b8428d97cf52c05c036221 (127.20.132.1:39487)
I20260812 06:20:25.412168 21008 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012076506s
I20260812 06:20:25.413043 21385 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33346
I20260812 06:20:25.419791 21385 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33360:
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:20:25.428964 21543 tablet_service.cc:1511] Processing CreateTablet for tablet 8d3a86a12d78433d9524d681ec5d71af (DEFAULT_TABLE table=heavy-update-compaction-test [id=a8922224c21047be953ac301882df358]), partition=
I20260812 06:20:25.429277 21543 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8d3a86a12d78433d9524d681ec5d71af. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.431293 21627 tablet_bootstrap.cc:492] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Bootstrap starting.
I20260812 06:20:25.432169 21627 tablet_bootstrap.cc:654] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.433326 21627 tablet_bootstrap.cc:492] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: No bootstrap required, opened a new log
I20260812 06:20:25.433439 21627 ts_tablet_manager.cc:1403] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:25.433939 21627 raft_consensus.cc:359] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e32cf383d6b8428d97cf52c05c036221" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 39487 } }
I20260812 06:20:25.434067 21627 raft_consensus.cc:385] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.434140 21627 raft_consensus.cc:740] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e32cf383d6b8428d97cf52c05c036221, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.434301 21627 consensus_queue.cc:260] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [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: "e32cf383d6b8428d97cf52c05c036221" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 39487 } }
I20260812 06:20:25.434424 21627 raft_consensus.cc:399] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.434464 21627 raft_consensus.cc:493] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.434523 21627 raft_consensus.cc:3060] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.435289 21627 raft_consensus.cc:515] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e32cf383d6b8428d97cf52c05c036221" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 39487 } }
I20260812 06:20:25.435456 21627 leader_election.cc:304] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [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: e32cf383d6b8428d97cf52c05c036221; no voters: 
I20260812 06:20:25.435684 21627 leader_election.cc:290] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.435858 21630 raft_consensus.cc:2804] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.436110 21627 ts_tablet_manager.cc:1434] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:25.436126 21606 heartbeater.cc:499] Master 127.20.132.62:37825 was elected leader, sending a full tablet report...
I20260812 06:20:25.436137 21630 raft_consensus.cc:697] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 1 LEADER]: Becoming Leader. State: Replica: e32cf383d6b8428d97cf52c05c036221, State: Running, Role: LEADER
I20260812 06:20:25.436344 21630 consensus_queue.cc:237] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [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: "e32cf383d6b8428d97cf52c05c036221" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 39487 } }
I20260812 06:20:25.437752 21385 catalog_manager.cc:5719] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 reported cstate change: term changed from 0 to 1, leader changed from <none> to e32cf383d6b8428d97cf52c05c036221 (127.20.132.1). New cstate: current_term: 1 leader_uuid: "e32cf383d6b8428d97cf52c05c036221" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e32cf383d6b8428d97cf52c05c036221" member_type: VOTER last_known_addr { host: "127.20.132.1" port: 39487 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.500820 21008 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.007s
I20260812 06:20:25.651847 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af): perf score=19.054940
I20260812 06:20:25.806341 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.154s	user 0.113s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":891,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41092,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:25.806984 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling LogGCOp(8d3a86a12d78433d9524d681ec5d71af): free 20743880 bytes of WAL
I20260812 06:20:25.807221 21502 log_reader.cc:385] T 8d3a86a12d78433d9524d681ec5d71af: removed 2 log segments from log reader
I20260812 06:20:25.807271 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000001 (ops 1-6)
I20260812 06:20:25.807302 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000002 (ops 7-11)
I20260812 06:20:25.811841 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: LogGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:25.812191 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:25.829396 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.829898 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:25.991556 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.161s	user 0.101s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":440,"lbm_read_time_us":11384,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27813,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":375,"threads_started":5,"update_count":2000}
I20260812 06:20:25.992224 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=11.118625
I20260812 06:20:26.037618 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.045s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14767,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.038122 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:26.049050 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.049602 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af): 16411393 bytes on disk
I20260812 06:20:26.050137 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.050661 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:26.220209 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.169s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":873,"lbm_read_time_us":12314,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27792,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:20:26.220922 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:26.278671 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.058s	user 0.003s	sys 0.048s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24034,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.279249 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:26.292246 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.292799 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:26.494699 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.202s	user 0.124s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":987,"lbm_read_time_us":12539,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32687,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:26.495339 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:26.554450 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.059s	user 0.022s	sys 0.029s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24091,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.554919 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:26.566572 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.567065 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:26.732066 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.165s	user 0.115s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":13619,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31336,"lbm_writes_lt_1ms":543,"mutex_wait_us":102,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:20:26.732939 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=11.118625
I20260812 06:20:26.765583 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.032s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14242,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.766494 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:26.797940 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.031s	user 0.010s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":9426,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.798476 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:26.809864 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.810307 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:26.971797 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.161s	user 0.119s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":128,"lbm_read_time_us":13557,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31113,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":2500}
I20260812 06:20:26.972652 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=11.118625
I20260812 06:20:27.011704 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16915,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.012259 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.037819 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.025s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.038300 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.048197 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3832,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.048659 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:27.081981 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.033s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1245,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:27.082620 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling LogGCOp(8d3a86a12d78433d9524d681ec5d71af): free 112692367 bytes of WAL
I20260812 06:20:27.082854 21502 log_reader.cc:385] T 8d3a86a12d78433d9524d681ec5d71af: removed 11 log segments from log reader
I20260812 06:20:27.082902 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000003 (ops 12-16)
I20260812 06:20:27.082954 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000004 (ops 17-21)
I20260812 06:20:27.083036 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000005 (ops 22-26)
I20260812 06:20:27.083079 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000006 (ops 27-31)
I20260812 06:20:27.083098 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000007 (ops 32-36)
I20260812 06:20:27.083153 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000008 (ops 37-41)
I20260812 06:20:27.083195 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000009 (ops 42-46)
I20260812 06:20:27.083236 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000010 (ops 47-51)
I20260812 06:20:27.083276 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000011 (ops 52-56)
I20260812 06:20:27.083314 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000012 (ops 57-61)
I20260812 06:20:27.083354 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000013 (ops 62-66)
I20260812 06:20:27.108017 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: LogGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:27.108448 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af): 447 bytes on disk
I20260812 06:20:27.108963 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af) 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:20:27.109445 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.130935 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.021s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.131412 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.154635 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.023s	user 0.001s	sys 0.020s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.155195 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:27.413653 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.258s	user 0.170s	sys 0.077s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":902,"lbm_read_time_us":19975,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39719,"lbm_writes_lt_1ms":743,"mutex_wait_us":437,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":115,"threads_started":1,"update_count":3500}
I20260812 06:20:27.414212 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=18.063937
I20260812 06:20:27.482625 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.068s	user 0.038s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28935,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.483251 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.494220 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.494807 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:27.742822 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.248s	user 0.157s	sys 0.087s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":380,"lbm_read_time_us":16930,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40887,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":3000}
I20260812 06:20:27.743551 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=16.079562
I20260812 06:20:27.806965 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.063s	user 0.029s	sys 0.028s Metrics: {"bytes_written":17599606,"delete_count":0,"lbm_write_time_us":26896,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2145}
I20260812 06:20:27.807564 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.818151 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3323184,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:27.818600 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:27.829365 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.829800 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:28.070525 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.241s	user 0.173s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877195,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":418,"lbm_read_time_us":18257,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40140,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:20:28.071275 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:28.129789 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.058s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.130312 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:28.143366 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.143872 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:28.322465 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.178s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":12648,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29018,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:20:28.323244 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:28.380108 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.057s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25712,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.380959 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:28.401194 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.020s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.401712 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:28.581427 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.179s	user 0.131s	sys 0.047s 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":676,"lbm_read_time_us":13751,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29333,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":2500}
I20260812 06:20:28.582309 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:28.647696 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.065s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23689,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.648468 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:28.661057 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.661568 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:28.699190 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.037s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1448,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1609,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:28.699901 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling LogGCOp(8d3a86a12d78433d9524d681ec5d71af): free 123804199 bytes of WAL
I20260812 06:20:28.700141 21502 log_reader.cc:385] T 8d3a86a12d78433d9524d681ec5d71af: removed 12 log segments from log reader
I20260812 06:20:28.700206 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000014 (ops 67-70)
I20260812 06:20:28.700258 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000015 (ops 71-75)
I20260812 06:20:28.700316 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000016 (ops 76-80)
I20260812 06:20:28.700361 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000017 (ops 81-85)
I20260812 06:20:28.700398 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000018 (ops 86-90)
I20260812 06:20:28.700438 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000019 (ops 91-95)
I20260812 06:20:28.700477 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000020 (ops 96-100)
I20260812 06:20:28.700513 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000021 (ops 101-105)
I20260812 06:20:28.700554 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000022 (ops 106-110)
I20260812 06:20:28.700593 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000023 (ops 111-115)
I20260812 06:20:28.700634 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000024 (ops 116-120)
I20260812 06:20:28.700673 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000025 (ops 121-124)
I20260812 06:20:28.729351 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: LogGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.029s	user 0.003s	sys 0.026s Metrics: {}
I20260812 06:20:28.729749 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af): 461 bytes on disk
I20260812 06:20:28.730187 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.730731 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=3.181125
I20260812 06:20:28.750402 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4683,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.750905 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:28.760818 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.010s	user 0.006s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.761318 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:29.005280 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.244s	user 0.153s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":372,"lbm_read_time_us":19868,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42123,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:20:29.006063 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=18.063937
I20260812 06:20:29.063263 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.057s	user 0.027s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25646,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:29.063792 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:29.079944 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.080756 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:29.267431 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.186s	user 0.138s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":14346,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37893,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:20:29.268457 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:29.323323 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.055s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.323899 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:29.340813 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.341409 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:29.530910 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.189s	user 0.141s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1012,"lbm_read_time_us":16226,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34833,"lbm_writes_lt_1ms":543,"mutex_wait_us":405,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:20:29.531816 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=13.103000
I20260812 06:20:29.584859 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.053s	user 0.013s	sys 0.036s Metrics: {"bytes_written":14809962,"delete_count":0,"lbm_write_time_us":23435,"lbm_writes_lt_1ms":364,"reinsert_count":0,"update_count":1805}
I20260812 06:20:29.585561 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:29.594630 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.009s	user 0.001s	sys 0.003s Metrics: {"bytes_written":2010381,"delete_count":0,"lbm_write_time_us":2202,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:20:29.595196 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:29.776188 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.181s	user 0.130s	sys 0.041s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082472,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":476,"lbm_read_time_us":11668,"lbm_reads_lt_1ms":474,"lbm_write_time_us":30500,"lbm_writes_lt_1ms":453,"mutex_wait_us":38,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2050}
I20260812 06:20:29.778189 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:29.840472 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.062s	user 0.034s	sys 0.025s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":28258,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:20:29.841024 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:29.864383 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.023s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.864954 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:30.076212 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.211s	user 0.131s	sys 0.069s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364447,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":730,"lbm_read_time_us":15653,"lbm_reads_lt_1ms":562,"lbm_write_time_us":31569,"lbm_writes_lt_1ms":533,"mutex_wait_us":347,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":64896,"update_count":2450}
I20260812 06:20:30.077137 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:30.132143 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.055s	user 0.015s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21018,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.132679 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:30.145859 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.146601 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:30.353483 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.207s	user 0.141s	sys 0.056s 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":224,"lbm_read_time_us":12117,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34010,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:20:30.354718 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=14.095187
I20260812 06:20:30.414126 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.059s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.414654 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=2.188937
I20260812 06:20:30.427071 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.427665 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:30.462237 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushMRSOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1868,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:30.462946 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling LogGCOp(8d3a86a12d78433d9524d681ec5d71af): free 129320766 bytes of WAL
I20260812 06:20:30.463200 21502 log_reader.cc:385] T 8d3a86a12d78433d9524d681ec5d71af: removed 13 log segments from log reader
I20260812 06:20:30.463248 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000026 (ops 125-129)
I20260812 06:20:30.463279 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000027 (ops 130-134)
I20260812 06:20:30.463340 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000028 (ops 135-139)
I20260812 06:20:30.463390 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000029 (ops 140-144)
I20260812 06:20:30.463429 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000030 (ops 145-149)
I20260812 06:20:30.463475 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000031 (ops 150-154)
I20260812 06:20:30.463522 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000032 (ops 155-158)
I20260812 06:20:30.463562 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000033 (ops 159-163)
I20260812 06:20:30.463600 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000034 (ops 164-168)
I20260812 06:20:30.463637 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000035 (ops 169-172)
I20260812 06:20:30.463675 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000036 (ops 173-177)
I20260812 06:20:30.463713 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000037 (ops 178-182)
I20260812 06:20:30.463752 21502 log.cc:1079] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: Deleting log segment in path: /tmp/dist-test-task__kPgR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619361605-21008-0/minicluster-data/ts-0-root/wals/8d3a86a12d78433d9524d681ec5d71af/wal-000000038 (ops 183-187)
I20260812 06:20:30.494062 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: LogGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:30.494727 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=6.157687
I20260812 06:20:30.520007 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.025s	user 0.022s	sys 0.000s Metrics: {"bytes_written":8082005,"delete_count":0,"lbm_write_time_us":10887,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:20:30.520517 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af): 493 bytes on disk
I20260812 06:20:30.521032 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: UndoDeltaBlockGCOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.521620 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af): perf score=1.000000
I20260812 06:20:30.779584 21008 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.279s	user 1.913s	sys 0.165s
I20260812 06:20:30.795598 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: MajorDeltaCompactionOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.274s	user 0.147s	sys 0.116s Metrics: {"cfile_cache_miss":730,"cfile_cache_miss_bytes":32856560,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":997,"lbm_read_time_us":17993,"lbm_reads_lt_1ms":766,"lbm_write_time_us":44061,"lbm_writes_lt_1ms":740,"mutex_wait_us":331,"peak_mem_usage":86805555,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":100,"threads_started":1,"update_count":3485}
I20260812 06:20:30.796548 21607 maintenance_manager.cc:419] P e32cf383d6b8428d97cf52c05c036221: Scheduling FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af): perf score=19.056125
I20260812 06:20:30.843314 21008 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.063s	user 0.001s	sys 0.000s
I20260812 06:20:30.843927 21008 tablet_server.cc:179] TabletServer@127.20.132.1:0 shutting down...
I20260812 06:20:30.854666 21502 maintenance_manager.cc:643] P e32cf383d6b8428d97cf52c05c036221: FlushDeltaMemStoresOp(8d3a86a12d78433d9524d681ec5d71af) complete. Timing: real 0.058s	user 0.036s	sys 0.020s Metrics: {"bytes_written":20635393,"delete_count":0,"lbm_write_time_us":25885,"lbm_writes_lt_1ms":506,"reinsert_count":0,"update_count":2515}
I20260812 06:20:30.855280 21008 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.855520 21008 tablet_replica.cc:333] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221: stopping tablet replica
I20260812 06:20:30.855675 21008 raft_consensus.cc:2243] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.855878 21008 raft_consensus.cc:2272] T 8d3a86a12d78433d9524d681ec5d71af P e32cf383d6b8428d97cf52c05c036221 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.859402 21008 tablet_server.cc:196] TabletServer@127.20.132.1:0 shutdown complete.
I20260812 06:20:30.862222 21008 master.cc:562] Master@127.20.132.62:37825 shutting down...
I20260812 06:20:30.866376 21008 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.866518 21008 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.866567 21008 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2e4b86b2c7824f5e86d229061e59fb83: stopping tablet replica
I20260812 06:20:30.879159 21008 master.cc:584] Master@127.20.132.62:37825 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5686 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11606 ms total)

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