[==========] 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:17:00.366971 23303 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.193.254:46431
I20260812 06:17:00.367964 23303 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:17:00.368572 23303 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.375249 23317 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:17:00.375296 23319 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:17:00.375414 23303 server_base.cc:1061] running on GCE node
W20260812 06:17:00.375504 23315 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:17:00.375972 23303 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.376097 23303 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:17:00.376157 23303 hybrid_clock.cc:648] HybridClock initialized: now 1786515420376154 us; error 0 us; skew 500 ppm
I20260812 06:17:00.377864 23303 webserver.cc:533] Webserver started at http://127.22.193.254:42145/ using document root <none> and password file <none>
I20260812 06:17:00.378453 23303 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.378544 23303 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.378789 23303 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.380347 23303 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/master-0-root/instance:
uuid: "8c34910d77874c31b63228dc4e3787b0"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-7nm7"
I20260812 06:17:00.383736 23303 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:17:00.385712 23329 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:17:00.386679 23303 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:00.386804 23303 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/master-0-root
uuid: "8c34910d77874c31b63228dc4e3787b0"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-7nm7"
I20260812 06:17:00.386902 23303 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-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:17:00.407460 23303 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.408142 23303 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:17:00.408329 23303 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.415807 23303 rpc_server.cc:307] RPC server started. Bound to: 127.22.193.254:46431
I20260812 06:17:00.415817 23419 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.193.254:46431 every 8 connection(s)
I20260812 06:17:00.418054 23423 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:17:00.423357 23423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: Bootstrap starting.
I20260812 06:17:00.425676 23423 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.426590 23423 log.cc:826] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:00.428176 23423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: No bootstrap required, opened a new log
I20260812 06:17:00.430996 23423 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER }
I20260812 06:17:00.431160 23423 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.431216 23423 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c34910d77874c31b63228dc4e3787b0, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.431855 23423 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [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: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER }
I20260812 06:17:00.432001 23423 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.432065 23423 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.432152 23423 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.432909 23423 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER }
I20260812 06:17:00.433310 23423 leader_election.cc:304] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [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: 8c34910d77874c31b63228dc4e3787b0; no voters: 
I20260812 06:17:00.433621 23423 leader_election.cc:290] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.433754 23428 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.434036 23428 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 1 LEADER]: Becoming Leader. State: Replica: 8c34910d77874c31b63228dc4e3787b0, State: Running, Role: LEADER
I20260812 06:17:00.434518 23428 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [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: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER }
I20260812 06:17:00.434652 23423 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:00.436815 23431 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8c34910d77874c31b63228dc4e3787b0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER } }
I20260812 06:17:00.436820 23433 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8c34910d77874c31b63228dc4e3787b0. Latest consensus state: current_term: 1 leader_uuid: "8c34910d77874c31b63228dc4e3787b0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c34910d77874c31b63228dc4e3787b0" member_type: VOTER } }
I20260812 06:17:00.436971 23431 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.436971 23433 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.437252 23303 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:00.439730 23456 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:00.439819 23456 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:00.439885 23458 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:00.441035 23458 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:00.447829 23458 catalog_manager.cc:1383] Generated new cluster ID: a09c7b83bd754de1831aa2ca36e855c3
I20260812 06:17:00.448030 23458 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:00.458673 23458 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:00.459465 23458 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:00.467528 23458 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: Generated new TSK 0
I20260812 06:17:00.468097 23458 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:00.469699 23303 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.472263 23462 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:17:00.472295 23465 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:17:00.472415 23463 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:17:00.472631 23303 server_base.cc:1061] running on GCE node
I20260812 06:17:00.472824 23303 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.472888 23303 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:17:00.472922 23303 hybrid_clock.cc:648] HybridClock initialized: now 1786515420472922 us; error 0 us; skew 500 ppm
I20260812 06:17:00.473817 23303 webserver.cc:533] Webserver started at http://127.22.193.193:34977/ using document root <none> and password file <none>
I20260812 06:17:00.474023 23303 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.474133 23303 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.474215 23303 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.474620 23303 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/instance:
uuid: "2da7ef21df3c46d49d9fc9d53c8ee788"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-7nm7"
I20260812 06:17:00.476123 23303 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:00.477165 23475 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:17:00.477445 23303 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:00.477535 23303 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root
uuid: "2da7ef21df3c46d49d9fc9d53c8ee788"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-7nm7"
I20260812 06:17:00.477631 23303 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-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:17:00.490988 23303 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.491484 23303 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.492015 23303 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:00.492839 23303 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:00.492890 23303 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.492957 23303 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:00.492997 23303 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.500197 23303 rpc_server.cc:307] RPC server started. Bound to: 127.22.193.193:40829
I20260812 06:17:00.500236 23593 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.193.193:40829 every 8 connection(s)
I20260812 06:17:00.511178 23594 heartbeater.cc:344] Connected to a master server at 127.22.193.254:46431
I20260812 06:17:00.511482 23594 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:00.512032 23594 heartbeater.cc:507] Master 127.22.193.254:46431 requested a full tablet report, sending...
I20260812 06:17:00.513885 23359 ts_manager.cc:194] Registered new tserver with Master: 2da7ef21df3c46d49d9fc9d53c8ee788 (127.22.193.193:40829)
I20260812 06:17:00.514364 23303 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013526645s
I20260812 06:17:00.515215 23359 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52774
I20260812 06:17:00.524103 23359 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52778:
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:17:00.537683 23515 tablet_service.cc:1511] Processing CreateTablet for tablet f42061f6aabc476d88c4b8b6a204545f (DEFAULT_TABLE table=heavy-update-compaction-test [id=44aa6967fd0d40868edc1f4fd0dc48d9]), partition=
I20260812 06:17:00.538115 23515 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f42061f6aabc476d88c4b8b6a204545f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:00.540774 23610 tablet_bootstrap.cc:492] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Bootstrap starting.
I20260812 06:17:00.541852 23610 tablet_bootstrap.cc:654] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.542990 23610 tablet_bootstrap.cc:492] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: No bootstrap required, opened a new log
I20260812 06:17:00.543109 23610 ts_tablet_manager.cc:1403] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:00.543550 23610 raft_consensus.cc:359] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2da7ef21df3c46d49d9fc9d53c8ee788" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40829 } }
I20260812 06:17:00.543677 23610 raft_consensus.cc:385] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.543728 23610 raft_consensus.cc:740] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2da7ef21df3c46d49d9fc9d53c8ee788, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.543871 23610 consensus_queue.cc:260] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [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: "2da7ef21df3c46d49d9fc9d53c8ee788" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40829 } }
I20260812 06:17:00.543988 23610 raft_consensus.cc:399] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.544036 23610 raft_consensus.cc:493] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.544090 23610 raft_consensus.cc:3060] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.544963 23610 raft_consensus.cc:515] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2da7ef21df3c46d49d9fc9d53c8ee788" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40829 } }
I20260812 06:17:00.545109 23610 leader_election.cc:304] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [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: 2da7ef21df3c46d49d9fc9d53c8ee788; no voters: 
I20260812 06:17:00.545393 23610 leader_election.cc:290] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.545482 23612 raft_consensus.cc:2804] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.545680 23612 raft_consensus.cc:697] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 1 LEADER]: Becoming Leader. State: Replica: 2da7ef21df3c46d49d9fc9d53c8ee788, State: Running, Role: LEADER
I20260812 06:17:00.545780 23610 ts_tablet_manager.cc:1434] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:00.545877 23612 consensus_queue.cc:237] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [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: "2da7ef21df3c46d49d9fc9d53c8ee788" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40829 } }
I20260812 06:17:00.546059 23594 heartbeater.cc:499] Master 127.22.193.254:46431 was elected leader, sending a full tablet report...
I20260812 06:17:00.548439 23359 catalog_manager.cc:5719] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2da7ef21df3c46d49d9fc9d53c8ee788 (127.22.193.193). New cstate: current_term: 1 leader_uuid: "2da7ef21df3c46d49d9fc9d53c8ee788" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2da7ef21df3c46d49d9fc9d53c8ee788" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40829 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:00.619978 23303 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.009s	sys 0.017s
I20260812 06:17:00.751482 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f): perf score=15.086190
I20260812 06:17:00.923105 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.171s	user 0.114s	sys 0.055s Metrics: {"bytes_written":12922855,"cfile_init":1,"compiler_manager_pool.queue_time_us":196,"delete_count":0,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":881,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43813,"lbm_writes_lt_1ms":682,"mutex_wait_us":1051,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":141056,"thread_start_us":137,"threads_started":1,"update_count":1575}
I20260812 06:17:00.924250 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling LogGCOp(f42061f6aabc476d88c4b8b6a204545f): free 20743880 bytes of WAL
I20260812 06:17:00.924544 23480 log_reader.cc:385] T f42061f6aabc476d88c4b8b6a204545f: removed 2 log segments from log reader
I20260812 06:17:00.924607 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000001 (ops 1-6)
I20260812 06:17:00.924656 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000002 (ops 7-11)
I20260812 06:17:00.930716 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: LogGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:17:00.931054 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=5.165500
I20260812 06:17:00.954727 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.024s	user 0.014s	sys 0.009s Metrics: {"bytes_written":6892313,"delete_count":0,"lbm_write_time_us":10185,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:17:00.955230 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f): 12719213 bytes on disk
I20260812 06:17:00.955842 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.956274 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:01.146737 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.190s	user 0.109s	sys 0.068s Metrics: {"cfile_cache_miss":515,"cfile_cache_miss_bytes":24077290,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":13430,"lbm_reads_lt_1ms":547,"lbm_write_time_us":31098,"lbm_writes_lt_1ms":526,"peak_mem_usage":60337537,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":387,"threads_started":5,"update_count":2415}
I20260812 06:17:01.147346 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=15.087375
I20260812 06:17:01.209439 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.062s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16697073,"delete_count":0,"lbm_write_time_us":25373,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2035}
I20260812 06:17:01.210016 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:01.221648 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.222122 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:01.390146 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.168s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":539,"cfile_cache_miss_bytes":25061860,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":13806,"lbm_reads_lt_1ms":579,"lbm_write_time_us":32751,"lbm_writes_lt_1ms":550,"mutex_wait_us":42,"peak_mem_usage":63403145,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2535}
I20260812 06:17:01.390770 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:01.443703 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.053s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.444170 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:01.455751 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.456182 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:01.624752 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.168s	user 0.127s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":13790,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36187,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:01.625415 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=11.118625
I20260812 06:17:01.665820 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17544,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.666383 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:01.693403 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.027s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6502,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.693908 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:01.705655 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.706290 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:01.877849 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.171s	user 0.116s	sys 0.042s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":787,"lbm_read_time_us":12165,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30814,"lbm_writes_lt_1ms":543,"mutex_wait_us":442,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:01.882005 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:01.941999 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.059s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23667,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.942471 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:01.953691 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.954382 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:02.142516 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.188s	user 0.114s	sys 0.073s 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":858,"lbm_read_time_us":13375,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31412,"lbm_writes_lt_1ms":543,"mutex_wait_us":388,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":99328,"update_count":2500}
I20260812 06:17:02.143252 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:02.199894 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.056s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25368,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.200392 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:02.235728 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.035s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":355,"dirs.run_wall_time_us":1373,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1820,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:02.236912 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling LogGCOp(f42061f6aabc476d88c4b8b6a204545f): free 112239276 bytes of WAL
I20260812 06:17:02.237196 23480 log_reader.cc:385] T f42061f6aabc476d88c4b8b6a204545f: removed 11 log segments from log reader
I20260812 06:17:02.237275 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000003 (ops 12-16)
I20260812 06:17:02.237326 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000004 (ops 17-20)
I20260812 06:17:02.237386 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000005 (ops 21-25)
I20260812 06:17:02.237427 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000006 (ops 26-30)
I20260812 06:17:02.237466 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000007 (ops 31-35)
I20260812 06:17:02.237504 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000008 (ops 36-40)
I20260812 06:17:02.237540 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000009 (ops 41-45)
I20260812 06:17:02.237577 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000010 (ops 46-50)
I20260812 06:17:02.237615 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000011 (ops 51-55)
I20260812 06:17:02.237651 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000012 (ops 56-60)
I20260812 06:17:02.237689 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000013 (ops 61-65)
I20260812 06:17:02.262286 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: LogGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:02.262774 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f): 462 bytes on disk
I20260812 06:17:02.263248 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f) 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:17:02.263720 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=6.157687
I20260812 06:17:02.303056 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.039s	user 0.004s	sys 0.022s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":11928,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:02.303545 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling LogGCOp(f42061f6aabc476d88c4b8b6a204545f): free 12017983 bytes of WAL
I20260812 06:17:02.303745 23480 log_reader.cc:385] T f42061f6aabc476d88c4b8b6a204545f: removed 1 log segments from log reader
I20260812 06:17:02.303799 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000014 (ops 66-70)
I20260812 06:17:02.306438 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: LogGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:02.306725 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:02.319152 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.319749 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:02.539844 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.220s	user 0.135s	sys 0.085s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979636,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":545,"lbm_read_time_us":17391,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42033,"lbm_writes_lt_1ms":743,"mutex_wait_us":299,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:02.540591 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:02.584946 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.044s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.585521 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:02.606634 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.021s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.607286 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:02.773819 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.166s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":925,"lbm_read_time_us":11215,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31608,"lbm_writes_lt_1ms":543,"mutex_wait_us":435,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2500}
I20260812 06:17:02.774380 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:02.830767 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.056s	user 0.021s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.831218 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:02.995708 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.164s	user 0.101s	sys 0.063s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":233,"lbm_read_time_us":11600,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28294,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:17:02.996309 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:03.050911 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.054s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21213,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.051390 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:03.068403 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.068929 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:03.257436 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.188s	user 0.114s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":12344,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30972,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31744,"update_count":2500}
I20260812 06:17:03.257972 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:03.312981 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.055s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.313845 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:03.328001 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.328538 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:03.488893 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.160s	user 0.109s	sys 0.041s 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":712,"lbm_read_time_us":10160,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32093,"lbm_writes_lt_1ms":543,"mutex_wait_us":326,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:17:03.489530 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:03.539920 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.050s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22346,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.540547 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:03.556543 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.557056 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:03.723986 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.167s	user 0.119s	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":192,"lbm_read_time_us":12166,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34238,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:03.724691 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=11.118625
I20260812 06:17:03.769366 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17173,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:03.769829 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:03.783020 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.783524 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:03.793156 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.009s	user 0.005s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3660,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.793713 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:03.828377 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1065,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2020,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:03.829299 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling LogGCOp(f42061f6aabc476d88c4b8b6a204545f): free 120553382 bytes of WAL
I20260812 06:17:03.829596 23480 log_reader.cc:385] T f42061f6aabc476d88c4b8b6a204545f: removed 12 log segments from log reader
I20260812 06:17:03.829676 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000015 (ops 71-75)
I20260812 06:17:03.829737 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000016 (ops 76-80)
I20260812 06:17:03.829805 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000017 (ops 81-84)
I20260812 06:17:03.829855 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000018 (ops 85-89)
I20260812 06:17:03.829900 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000019 (ops 90-94)
I20260812 06:17:03.829944 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000020 (ops 95-98)
I20260812 06:17:03.830044 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000021 (ops 99-103)
I20260812 06:17:03.830098 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000022 (ops 104-108)
I20260812 06:17:03.830142 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000023 (ops 109-113)
I20260812 06:17:03.830188 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000024 (ops 114-118)
I20260812 06:17:03.830255 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000025 (ops 119-123)
I20260812 06:17:03.830302 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000026 (ops 124-128)
I20260812 06:17:03.861191 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: LogGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.032s	user 0.006s	sys 0.022s Metrics: {}
I20260812 06:17:03.862067 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f): 482 bytes on disk
I20260812 06:17:03.862692 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.863454 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=6.157687
I20260812 06:17:03.886536 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.023s	user 0.014s	sys 0.008s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":9441,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:17:03.887039 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:04.125809 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.238s	user 0.176s	sys 0.050s Metrics: {"cfile_cache_miss":726,"cfile_cache_miss_bytes":32651550,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":322,"lbm_read_time_us":16853,"lbm_reads_lt_1ms":762,"lbm_write_time_us":38071,"lbm_writes_lt_1ms":735,"mutex_wait_us":53,"peak_mem_usage":86600380,"reinsert_count":0,"spinlock_wait_cycles":15616,"thread_start_us":77,"threads_started":1,"update_count":3460}
I20260812 06:17:04.126529 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=19.056125
I20260812 06:17:04.197098 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.070s	user 0.026s	sys 0.041s Metrics: {"bytes_written":20840512,"delete_count":0,"lbm_write_time_us":26121,"lbm_writes_lt_1ms":511,"reinsert_count":0,"update_count":2540}
I20260812 06:17:04.197611 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:04.208451 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.209164 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:04.417415 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.208s	user 0.142s	sys 0.065s Metrics: {"cfile_cache_miss":640,"cfile_cache_miss_bytes":29205298,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1153,"lbm_read_time_us":16992,"lbm_reads_lt_1ms":680,"lbm_write_time_us":36033,"lbm_writes_lt_1ms":651,"mutex_wait_us":413,"peak_mem_usage":75870752,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3040}
I20260812 06:17:04.418009 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:04.476369 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.058s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25557,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.476851 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:04.487725 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:17:04.488162 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:04.674392 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.186s	user 0.141s	sys 0.038s 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":328,"lbm_read_time_us":13017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29896,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:04.675104 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:04.738121 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.063s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.738758 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:04.749650 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.750105 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:04.939211 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.189s	user 0.120s	sys 0.059s 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":170,"lbm_read_time_us":13441,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31500,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:17:04.939950 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=14.095187
I20260812 06:17:05.002535 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.062s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20355,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.003031 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:05.013711 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4203,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.014194 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:05.195672 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.181s	user 0.128s	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":1061,"lbm_read_time_us":13115,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31120,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.196228 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=11.118625
I20260812 06:17:05.232293 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16006,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:05.233223 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:05.244393 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:05.244906 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:05.382841 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.138s	user 0.074s	sys 0.063s 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":497,"lbm_read_time_us":10193,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24772,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:05.383877 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=10.126437
I20260812 06:17:05.425848 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18774,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:05.426373 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=2.188937
I20260812 06:17:05.437393 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.437849 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:05.468482 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushMRSOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1374,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1539,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:05.469137 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling LogGCOp(f42061f6aabc476d88c4b8b6a204545f): free 133477656 bytes of WAL
I20260812 06:17:05.469358 23480 log_reader.cc:385] T f42061f6aabc476d88c4b8b6a204545f: removed 13 log segments from log reader
I20260812 06:17:05.469420 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000027 (ops 129-133)
I20260812 06:17:05.469473 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000028 (ops 134-138)
I20260812 06:17:05.469532 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000029 (ops 139-143)
I20260812 06:17:05.469574 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000030 (ops 144-148)
I20260812 06:17:05.469614 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000031 (ops 149-153)
I20260812 06:17:05.469653 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000032 (ops 154-158)
I20260812 06:17:05.469693 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000033 (ops 159-163)
I20260812 06:17:05.469732 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000034 (ops 164-168)
I20260812 06:17:05.469771 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000035 (ops 169-173)
I20260812 06:17:05.469810 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000036 (ops 174-178)
I20260812 06:17:05.469849 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000037 (ops 179-183)
I20260812 06:17:05.469887 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000038 (ops 184-188)
I20260812 06:17:05.469925 23480 log.cc:1079] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/f42061f6aabc476d88c4b8b6a204545f/wal-000000039 (ops 189-193)
I20260812 06:17:05.501784 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: LogGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:05.502205 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f): 483 bytes on disk
I20260812 06:17:05.502648 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: UndoDeltaBlockGCOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.503154 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=6.157687
I20260812 06:17:05.527751 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.024s	user 0.014s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9700,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:05.528342 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f): perf score=1.000000
I20260812 06:17:05.649134 23303 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.029s	user 1.798s	sys 0.158s
I20260812 06:17:05.709162 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: MajorDeltaCompactionOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.181s	user 0.135s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":13962,"lbm_reads_lt_1ms":661,"lbm_write_time_us":38342,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:05.709653 23596 maintenance_manager.cc:419] P 2da7ef21df3c46d49d9fc9d53c8ee788: Scheduling FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f): perf score=10.126437
I20260812 06:17:05.728050 23303 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.004s	sys 0.000s
I20260812 06:17:05.728798 23303 tablet_server.cc:179] TabletServer@127.22.193.193:0 shutting down...
I20260812 06:17:05.744866 23480 maintenance_manager.cc:643] P 2da7ef21df3c46d49d9fc9d53c8ee788: FlushDeltaMemStoresOp(f42061f6aabc476d88c4b8b6a204545f) complete. Timing: real 0.035s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15632,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:05.745436 23303 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:05.745888 23303 tablet_replica.cc:333] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788: stopping tablet replica
I20260812 06:17:05.746137 23303 raft_consensus.cc:2243] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.746440 23303 raft_consensus.cc:2272] T f42061f6aabc476d88c4b8b6a204545f P 2da7ef21df3c46d49d9fc9d53c8ee788 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.761620 23303 tablet_server.cc:196] TabletServer@127.22.193.193:0 shutdown complete.
I20260812 06:17:05.766927 23303 master.cc:562] Master@127.22.193.254:46431 shutting down...
I20260812 06:17:05.770813 23303 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.771005 23303 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.771088 23303 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8c34910d77874c31b63228dc4e3787b0: stopping tablet replica
I20260812 06:17:05.783329 23303 master.cc:584] Master@127.22.193.254:46431 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5512 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:05.894331 23303 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.193.254:38587
I20260812 06:17:05.894774 23303 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:05.897086 23303 server_base.cc:1061] running on GCE node
W20260812 06:17:05.897167 23644 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:17:05.897167 23642 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:17:05.897291 23641 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:17:05.897539 23303 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.897583 23303 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:17:05.897599 23303 hybrid_clock.cc:648] HybridClock initialized: now 1786515425897599 us; error 0 us; skew 500 ppm
I20260812 06:17:05.898469 23303 webserver.cc:533] Webserver started at http://127.22.193.254:44873/ using document root <none> and password file <none>
I20260812 06:17:05.898604 23303 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.898649 23303 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.898729 23303 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.899094 23303 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/master-0-root/instance:
uuid: "a6ccf66b83a3494194b38814d98b381c"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7nm7"
I20260812 06:17:05.900549 23303 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:05.901496 23651 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:17:05.901746 23303 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.901839 23303 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/master-0-root
uuid: "a6ccf66b83a3494194b38814d98b381c"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7nm7"
I20260812 06:17:05.901923 23303 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-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:17:05.918792 23303 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.919255 23303 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.923612 23303 rpc_server.cc:307] RPC server started. Bound to: 127.22.193.254:38587
I20260812 06:17:05.927842 23743 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.193.254:38587 every 8 connection(s)
I20260812 06:17:05.928436 23745 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:17:05.930441 23745 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c: Bootstrap starting.
I20260812 06:17:05.931210 23745 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.932425 23745 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c: No bootstrap required, opened a new log
I20260812 06:17:05.932787 23745 raft_consensus.cc:359] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER }
I20260812 06:17:05.932884 23745 raft_consensus.cc:385] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.932907 23745 raft_consensus.cc:740] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a6ccf66b83a3494194b38814d98b381c, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.933320 23745 consensus_queue.cc:260] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [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: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER }
I20260812 06:17:05.933437 23745 raft_consensus.cc:399] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.933466 23745 raft_consensus.cc:493] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.933499 23745 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.934394 23745 raft_consensus.cc:515] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER }
I20260812 06:17:05.934516 23745 leader_election.cc:304] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [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: a6ccf66b83a3494194b38814d98b381c; no voters: 
I20260812 06:17:05.934684 23745 leader_election.cc:290] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.934829 23750 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.935026 23750 raft_consensus.cc:697] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 1 LEADER]: Becoming Leader. State: Replica: a6ccf66b83a3494194b38814d98b381c, State: Running, Role: LEADER
I20260812 06:17:05.935160 23750 consensus_queue.cc:237] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [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: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER }
I20260812 06:17:05.935323 23745 sys_catalog.cc:565] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:05.935724 23751 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a6ccf66b83a3494194b38814d98b381c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER } }
I20260812 06:17:05.935755 23752 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [sys.catalog]: SysCatalogTable state changed. Reason: New leader a6ccf66b83a3494194b38814d98b381c. Latest consensus state: current_term: 1 leader_uuid: "a6ccf66b83a3494194b38814d98b381c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6ccf66b83a3494194b38814d98b381c" member_type: VOTER } }
I20260812 06:17:05.935817 23751 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.935838 23752 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.936066 23754 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:05.936941 23754 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:05.937157 23303 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:05.938983 23754 catalog_manager.cc:1383] Generated new cluster ID: f8f7c381d59d4f6b9fe55b7dca28f710
I20260812 06:17:05.939045 23754 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:05.957499 23754 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:05.958069 23754 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:05.964232 23754 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c: Generated new TSK 0
I20260812 06:17:05.964409 23754 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:05.969525 23303 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:05.971702 23303 server_base.cc:1061] running on GCE node
W20260812 06:17:05.971702 23792 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:17:05.971810 23787 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:17:05.971807 23783 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:17:05.972154 23303 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.972203 23303 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:17:05.972219 23303 hybrid_clock.cc:648] HybridClock initialized: now 1786515425972219 us; error 0 us; skew 500 ppm
I20260812 06:17:05.973151 23303 webserver.cc:533] Webserver started at http://127.22.193.193:43865/ using document root <none> and password file <none>
I20260812 06:17:05.973340 23303 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.973393 23303 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.973474 23303 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.973870 23303 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/instance:
uuid: "cc3f226593a84fd98b8dfbf10f34885d"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7nm7"
I20260812 06:17:05.975481 23303 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:05.976522 23799 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:17:05.976781 23303 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.976869 23303 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root
uuid: "cc3f226593a84fd98b8dfbf10f34885d"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7nm7"
I20260812 06:17:05.976963 23303 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-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:17:05.982754 23303 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.983090 23303 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.983395 23303 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:05.983841 23303 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:05.983901 23303 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.983960 23303 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:05.983995 23303 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.988546 23303 rpc_server.cc:307] RPC server started. Bound to: 127.22.193.193:40255
I20260812 06:17:05.989931 23902 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.193.193:40255 every 8 connection(s)
I20260812 06:17:05.998997 23904 heartbeater.cc:344] Connected to a master server at 127.22.193.254:38587
I20260812 06:17:05.999122 23904 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:05.999423 23904 heartbeater.cc:507] Master 127.22.193.254:38587 requested a full tablet report, sending...
I20260812 06:17:06.000140 23681 ts_manager.cc:194] Registered new tserver with Master: cc3f226593a84fd98b8dfbf10f34885d (127.22.193.193:40255)
I20260812 06:17:06.000845 23303 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011215116s
I20260812 06:17:06.000978 23681 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39254
I20260812 06:17:06.009217 23681 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39270:
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:17:06.018652 23838 tablet_service.cc:1511] Processing CreateTablet for tablet cdf8ec3164a54503a9afdf34dfe09f68 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5ee48026c3fc48039a33dfe7d133e3b9]), partition=
I20260812 06:17:06.018982 23838 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cdf8ec3164a54503a9afdf34dfe09f68. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:06.021159 23928 tablet_bootstrap.cc:492] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Bootstrap starting.
I20260812 06:17:06.022145 23928 tablet_bootstrap.cc:654] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:06.023336 23928 tablet_bootstrap.cc:492] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: No bootstrap required, opened a new log
I20260812 06:17:06.023447 23928 ts_tablet_manager.cc:1403] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:06.023864 23928 raft_consensus.cc:359] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cc3f226593a84fd98b8dfbf10f34885d" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40255 } }
I20260812 06:17:06.023979 23928 raft_consensus.cc:385] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:06.024027 23928 raft_consensus.cc:740] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cc3f226593a84fd98b8dfbf10f34885d, State: Initialized, Role: FOLLOWER
I20260812 06:17:06.024219 23928 consensus_queue.cc:260] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [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: "cc3f226593a84fd98b8dfbf10f34885d" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40255 } }
I20260812 06:17:06.024339 23928 raft_consensus.cc:399] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:06.024380 23928 raft_consensus.cc:493] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:06.024431 23928 raft_consensus.cc:3060] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:06.025350 23928 raft_consensus.cc:515] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cc3f226593a84fd98b8dfbf10f34885d" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40255 } }
I20260812 06:17:06.025468 23928 leader_election.cc:304] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [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: cc3f226593a84fd98b8dfbf10f34885d; no voters: 
I20260812 06:17:06.025635 23928 leader_election.cc:290] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:06.025787 23937 raft_consensus.cc:2804] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:06.025966 23928 ts_tablet_manager.cc:1434] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:06.025991 23904 heartbeater.cc:499] Master 127.22.193.254:38587 was elected leader, sending a full tablet report...
I20260812 06:17:06.026039 23937 raft_consensus.cc:697] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 1 LEADER]: Becoming Leader. State: Replica: cc3f226593a84fd98b8dfbf10f34885d, State: Running, Role: LEADER
I20260812 06:17:06.026188 23937 consensus_queue.cc:237] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [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: "cc3f226593a84fd98b8dfbf10f34885d" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40255 } }
I20260812 06:17:06.027627 23681 catalog_manager.cc:5719] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d reported cstate change: term changed from 0 to 1, leader changed from <none> to cc3f226593a84fd98b8dfbf10f34885d (127.22.193.193). New cstate: current_term: 1 leader_uuid: "cc3f226593a84fd98b8dfbf10f34885d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cc3f226593a84fd98b8dfbf10f34885d" member_type: VOTER last_known_addr { host: "127.22.193.193" port: 40255 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:06.090334 23303 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.019s	sys 0.004s
I20260812 06:17:06.240334 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=19.054940
I20260812 06:17:06.401885 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.161s	user 0.110s	sys 0.047s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":896,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43486,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:06.402784 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68): free 20743880 bytes of WAL
I20260812 06:17:06.402998 23808 log_reader.cc:385] T cdf8ec3164a54503a9afdf34dfe09f68: removed 2 log segments from log reader
I20260812 06:17:06.403079 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000001 (ops 1-6)
I20260812 06:17:06.403123 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000002 (ops 7-11)
I20260812 06:17:06.408001 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:06.408372 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:06.420544 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.421056 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68): 16411393 bytes on disk
I20260812 06:17:06.421617 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.422019 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:06.590512 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.168s	user 0.106s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":608,"lbm_read_time_us":12710,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26350,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":353,"threads_started":5,"update_count":2000}
I20260812 06:17:06.591166 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=11.118625
I20260812 06:17:06.639577 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.048s	user 0.032s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20381,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:06.640022 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:06.656649 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.016s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.657061 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:06.666857 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.667269 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:06.832731 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.165s	user 0.122s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2012,"lbm_read_time_us":12808,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31102,"lbm_writes_lt_1ms":543,"mutex_wait_us":465,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:06.833405 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=11.118625
I20260812 06:17:06.875782 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.042s	user 0.033s	sys 0.007s Metrics: {"bytes_written":13127975,"delete_count":0,"lbm_write_time_us":18550,"lbm_writes_lt_1ms":323,"reinsert_count":0,"update_count":1600}
I20260812 06:17:06.876345 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:06.897799 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":5315,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:06.898203 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:06.909250 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.909730 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:07.071811 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.162s	user 0.131s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774789,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":361,"lbm_read_time_us":12981,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32440,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":84608,"update_count":2500}
I20260812 06:17:07.072611 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=11.118625
I20260812 06:17:07.108008 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.035s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15437,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:07.108476 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:07.129757 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.130298 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:07.144980 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.145486 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:07.300944 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.155s	user 0.108s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":698,"lbm_read_time_us":11860,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32846,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:17:07.301631 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=10.126437
I20260812 06:17:07.337126 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.035s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16574,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.337882 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:07.353751 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.354621 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:07.483891 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.129s	user 0.112s	sys 0.016s 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":408,"lbm_read_time_us":9523,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25463,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:17:07.484664 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=10.126437
I20260812 06:17:07.535741 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.051s	user 0.018s	sys 0.031s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17835,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.536343 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:07.548957 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.549382 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:07.715675 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.166s	user 0.120s	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":193,"lbm_read_time_us":13121,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24906,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:17:07.716311 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=10.126437
I20260812 06:17:07.757947 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.041s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18499,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.758494 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:07.770867 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.771335 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:07.801949 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1270,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1555,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:07.802608 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68): free 124710248 bytes of WAL
I20260812 06:17:07.802879 23808 log_reader.cc:385] T cdf8ec3164a54503a9afdf34dfe09f68: removed 12 log segments from log reader
I20260812 06:17:07.802923 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000003 (ops 12-16)
I20260812 06:17:07.802953 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000004 (ops 17-21)
I20260812 06:17:07.802970 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000005 (ops 22-26)
I20260812 06:17:07.803035 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000006 (ops 27-31)
I20260812 06:17:07.803067 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000007 (ops 32-36)
I20260812 06:17:07.803117 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000008 (ops 37-41)
I20260812 06:17:07.803136 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000009 (ops 42-46)
I20260812 06:17:07.803195 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000010 (ops 47-51)
I20260812 06:17:07.803231 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000011 (ops 52-56)
I20260812 06:17:07.803277 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000012 (ops 57-61)
I20260812 06:17:07.803318 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000013 (ops 62-66)
I20260812 06:17:07.803346 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000014 (ops 67-71)
I20260812 06:17:07.834353 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:07.834775 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68): 482 bytes on disk
I20260812 06:17:07.835161 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.835589 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=6.157687
I20260812 06:17:07.866088 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.030s	user 0.026s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11722,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:07.866647 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:08.088215 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.221s	user 0.151s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":329,"lbm_read_time_us":14572,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38260,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:17:08.088984 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=15.087375
I20260812 06:17:08.165095 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.076s	user 0.029s	sys 0.032s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23471,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:08.165731 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=6.157687
I20260812 06:17:08.186765 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8305,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:08.187407 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:08.406375 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.219s	user 0.127s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":343,"lbm_read_time_us":16492,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34350,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":3000}
I20260812 06:17:08.407183 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=18.063937
I20260812 06:17:08.480269 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.073s	user 0.023s	sys 0.040s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32117,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:08.480780 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:08.492349 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.492993 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:08.728227 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.235s	user 0.136s	sys 0.087s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":16309,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37556,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:17:08.729122 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=18.063937
I20260812 06:17:08.804672 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.075s	user 0.043s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30365,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:08.805230 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:08.821512 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.822206 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:09.043416 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.221s	user 0.132s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":918,"lbm_read_time_us":15729,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36510,"lbm_writes_lt_1ms":643,"mutex_wait_us":409,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":3000}
I20260812 06:17:09.044149 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=16.079562
I20260812 06:17:09.099332 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.055s	user 0.033s	sys 0.017s Metrics: {"bytes_written":17681654,"delete_count":0,"lbm_write_time_us":22760,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:17:09.099874 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.111266 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3364213,"delete_count":0,"lbm_write_time_us":3846,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:17:09.111689 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.120864 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:17:09.121239 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:09.338791 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.217s	user 0.124s	sys 0.092s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877197,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":770,"lbm_read_time_us":17036,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35820,"lbm_writes_lt_1ms":643,"mutex_wait_us":349,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":3000}
I20260812 06:17:09.341845 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=15.087375
I20260812 06:17:09.390151 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.048s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21137,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:09.390879 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.412515 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5094,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.412951 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.423226 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.423635 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:09.459666 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.036s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":1179,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1696,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:09.460335 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68): free 133024409 bytes of WAL
I20260812 06:17:09.460556 23808 log_reader.cc:385] T cdf8ec3164a54503a9afdf34dfe09f68: removed 13 log segments from log reader
I20260812 06:17:09.460598 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000015 (ops 72-76)
I20260812 06:17:09.460626 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000016 (ops 77-81)
I20260812 06:17:09.460685 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000017 (ops 82-86)
I20260812 06:17:09.460736 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000018 (ops 87-91)
I20260812 06:17:09.460778 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000019 (ops 92-96)
I20260812 06:17:09.460819 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000020 (ops 97-101)
I20260812 06:17:09.460861 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000021 (ops 102-106)
I20260812 06:17:09.460903 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000022 (ops 107-111)
I20260812 06:17:09.460959 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000023 (ops 112-116)
I20260812 06:17:09.460996 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000024 (ops 117-121)
I20260812 06:17:09.461035 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000025 (ops 122-126)
I20260812 06:17:09.461077 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000026 (ops 127-130)
I20260812 06:17:09.461117 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000027 (ops 131-135)
I20260812 06:17:09.493350 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:09.493885 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=3.181125
I20260812 06:17:09.513499 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7843,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:09.513932 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.523689 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.524102 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68): 492 bytes on disk
I20260812 06:17:09.524555 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68) 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:17:09.525035 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:09.780169 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.255s	user 0.171s	sys 0.083s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082257,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":675,"lbm_read_time_us":21735,"lbm_reads_lt_1ms":875,"lbm_write_time_us":46138,"lbm_writes_lt_1ms":843,"mutex_wait_us":1,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":72,"threads_started":1,"update_count":4000}
I20260812 06:17:09.780696 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=18.063937
I20260812 06:17:09.865795 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.084s	user 0.045s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":38948,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:09.866312 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=3.181125
I20260812 06:17:09.886188 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.020s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4932,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:09.886711 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:09.896919 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.897356 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:10.088251 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.191s	user 0.138s	sys 0.048s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979624,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":545,"lbm_read_time_us":15825,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38877,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3500}
I20260812 06:17:10.089084 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=15.087375
I20260812 06:17:10.137418 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.048s	user 0.013s	sys 0.029s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20031,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:10.137962 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:10.153461 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.153977 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:10.166389 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.166872 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:10.346029 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.179s	user 0.148s	sys 0.027s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":211,"lbm_read_time_us":13507,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35423,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:17:10.346801 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=14.095187
I20260812 06:17:10.406852 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.060s	user 0.032s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27539,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.407454 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:10.428920 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.021s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.429410 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:10.603382 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.174s	user 0.137s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":893,"lbm_read_time_us":12380,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30965,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2500}
I20260812 06:17:10.604072 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=14.095187
I20260812 06:17:10.658290 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.054s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24148,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.658886 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:10.832083 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.173s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":450,"lbm_read_time_us":11851,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29036,"lbm_writes_lt_1ms":443,"mutex_wait_us":100,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:10.832715 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=14.095187
I20260812 06:17:10.890632 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.058s	user 0.021s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.891305 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:10.910190 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6512,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.910772 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:10.962911 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushMRSOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.052s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1494,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2349,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:10.963960 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68): 472 bytes on disk
I20260812 06:17:10.964428 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: UndoDeltaBlockGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:10.965073 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=3.181125
I20260812 06:17:10.985519 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.020s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7903,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:10.985968 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68): free 124710614 bytes of WAL
I20260812 06:17:10.986179 23808 log_reader.cc:385] T cdf8ec3164a54503a9afdf34dfe09f68: removed 12 log segments from log reader
I20260812 06:17:10.986269 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000028 (ops 136-140)
I20260812 06:17:10.986332 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000029 (ops 141-145)
I20260812 06:17:10.986375 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000030 (ops 146-150)
I20260812 06:17:10.986394 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000031 (ops 151-155)
I20260812 06:17:10.986449 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000032 (ops 156-160)
I20260812 06:17:10.986497 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000033 (ops 161-165)
I20260812 06:17:10.986536 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000034 (ops 166-170)
I20260812 06:17:10.986574 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000035 (ops 171-175)
I20260812 06:17:10.986613 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000036 (ops 176-180)
I20260812 06:17:10.986650 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000037 (ops 181-185)
I20260812 06:17:10.986692 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000038 (ops 186-190)
I20260812 06:17:10.986737 23808 log.cc:1079] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: Deleting log segment in path: /tmp/dist-test-taskFPDjXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420356293-23303-0/minicluster-data/ts-0-root/wals/cdf8ec3164a54503a9afdf34dfe09f68/wal-000000039 (ops 191-195)
I20260812 06:17:11.016240 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: LogGCOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.030s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:11.016798 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:11.036695 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.037142 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=2.188937
I20260812 06:17:11.048722 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: FlushDeltaMemStoresOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.049182 23906 maintenance_manager.cc:419] P cc3f226593a84fd98b8dfbf10f34885d: Scheduling MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68): perf score=1.000000
I20260812 06:17:11.081928 23303 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.991s	user 1.790s	sys 0.181s
I20260812 06:17:11.200109 23303 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.118s	user 0.001s	sys 0.000s
I20260812 06:17:11.200627 23303 tablet_server.cc:179] TabletServer@127.22.193.193:0 shutting down...
I20260812 06:17:11.286358 23808 maintenance_manager.cc:643] P cc3f226593a84fd98b8dfbf10f34885d: MajorDeltaCompactionOp(cdf8ec3164a54503a9afdf34dfe09f68) complete. Timing: real 0.237s	user 0.156s	sys 0.080s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082271,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":947,"lbm_read_time_us":19524,"lbm_reads_lt_1ms":871,"lbm_write_time_us":38396,"lbm_writes_lt_1ms":843,"mutex_wait_us":380,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":60672,"thread_start_us":116,"threads_started":1,"update_count":4000}
I20260812 06:17:11.287207 23303 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:11.287575 23303 tablet_replica.cc:333] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d: stopping tablet replica
I20260812 06:17:11.287720 23303 raft_consensus.cc:2243] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:11.287901 23303 raft_consensus.cc:2272] T cdf8ec3164a54503a9afdf34dfe09f68 P cc3f226593a84fd98b8dfbf10f34885d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:11.303959 23303 tablet_server.cc:196] TabletServer@127.22.193.193:0 shutdown complete.
I20260812 06:17:11.357784 23303 master.cc:562] Master@127.22.193.254:38587 shutting down...
I20260812 06:17:11.361374 23303 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:11.361547 23303 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:11.361591 23303 tablet_replica.cc:333] T 00000000000000000000000000000000 P a6ccf66b83a3494194b38814d98b381c: stopping tablet replica
I20260812 06:17:11.374176 23303 master.cc:584] Master@127.22.193.254:38587 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5588 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11102 ms total)

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