[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:23.281617 21948 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.111.62:34127
I20260812 06:16:23.282608 21948 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:23.283198 21948 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.289307 21958 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:23.289363 21957 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:23.289565 21948 server_base.cc:1061] running on GCE node
W20260812 06:16:23.289614 21960 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:23.290066 21948 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.290167 21948 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:23.290210 21948 hybrid_clock.cc:648] HybridClock initialized: now 1786515383290207 us; error 0 us; skew 500 ppm
I20260812 06:16:23.291918 21948 webserver.cc:533] Webserver started at http://127.21.111.62:44215/ using document root <none> and password file <none>
I20260812 06:16:23.292438 21948 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.292501 21948 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.292729 21948 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.294374 21948 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/master-0-root/instance:
uuid: "f703db55842b4ae1a10ea51ce88c8c7f"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-nj21"
I20260812 06:16:23.297926 21948 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:16:23.299945 21968 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.300889 21948 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:23.301002 21948 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/master-0-root
uuid: "f703db55842b4ae1a10ea51ce88c8c7f"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-nj21"
I20260812 06:16:23.301093 21948 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:23.313102 21948 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.313637 21948 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:23.313778 21948 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.320721 22062 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.111.62:34127 every 8 connection(s)
I20260812 06:16:23.320726 21948 rpc_server.cc:307] RPC server started. Bound to: 127.21.111.62:34127
I20260812 06:16:23.322882 22065 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.328238 22065 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: Bootstrap starting.
I20260812 06:16:23.330569 22065 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.331447 22065 log.cc:826] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:23.333050 22065 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: No bootstrap required, opened a new log
I20260812 06:16:23.335748 22065 raft_consensus.cc:359] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER }
I20260812 06:16:23.335914 22065 raft_consensus.cc:385] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.335983 22065 raft_consensus.cc:740] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f703db55842b4ae1a10ea51ce88c8c7f, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.336565 22065 consensus_queue.cc:260] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [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: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER }
I20260812 06:16:23.336714 22065 raft_consensus.cc:399] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.336779 22065 raft_consensus.cc:493] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.336899 22065 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.337631 22065 raft_consensus.cc:515] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER }
I20260812 06:16:23.338054 22065 leader_election.cc:304] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [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: f703db55842b4ae1a10ea51ce88c8c7f; no voters: 
I20260812 06:16:23.338340 22065 leader_election.cc:290] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.338447 22069 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.338660 22069 raft_consensus.cc:697] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 1 LEADER]: Becoming Leader. State: Replica: f703db55842b4ae1a10ea51ce88c8c7f, State: Running, Role: LEADER
I20260812 06:16:23.339069 22069 consensus_queue.cc:237] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [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: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER }
I20260812 06:16:23.339282 22065 sys_catalog.cc:565] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:23.340840 22071 sys_catalog.cc:455] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER } }
I20260812 06:16:23.340889 22072 sys_catalog.cc:455] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [sys.catalog]: SysCatalogTable state changed. Reason: New leader f703db55842b4ae1a10ea51ce88c8c7f. Latest consensus state: current_term: 1 leader_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f703db55842b4ae1a10ea51ce88c8c7f" member_type: VOTER } }
I20260812 06:16:23.340956 22071 sys_catalog.cc:458] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.340992 22072 sys_catalog.cc:458] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.341358 22091 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:23.341526 21948 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:23.343487 22091 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:23.347708 22091 catalog_manager.cc:1383] Generated new cluster ID: e77db0ed15c64f5c80f3cfc84188db8e
I20260812 06:16:23.347767 22091 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:23.363090 22091 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:23.364006 22091 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:23.369045 22091 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: Generated new TSK 0
I20260812 06:16:23.369652 22091 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.373860 21948 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.376327 22108 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:23.376416 22106 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:23.376431 22105 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:23.376716 21948 server_base.cc:1061] running on GCE node
I20260812 06:16:23.376885 21948 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.377022 21948 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:23.377075 21948 hybrid_clock.cc:648] HybridClock initialized: now 1786515383377075 us; error 0 us; skew 500 ppm
I20260812 06:16:23.377907 21948 webserver.cc:533] Webserver started at http://127.21.111.1:36179/ using document root <none> and password file <none>
I20260812 06:16:23.378052 21948 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.378103 21948 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.378176 21948 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.378539 21948 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/instance:
uuid: "52cb942d666f4f0094feb7a81086912a"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-nj21"
I20260812 06:16:23.379978 21948 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:16:23.380920 22115 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.381176 21948 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.381238 21948 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root
uuid: "52cb942d666f4f0094feb7a81086912a"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-nj21"
I20260812 06:16:23.381309 21948 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:23.387643 21948 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.388036 21948 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.388458 21948 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.389240 21948 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.389289 21948 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.389331 21948 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.389361 21948 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.395246 21948 rpc_server.cc:307] RPC server started. Bound to: 127.21.111.1:33827
I20260812 06:16:23.395287 22223 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.111.1:33827 every 8 connection(s)
I20260812 06:16:23.408083 22226 heartbeater.cc:344] Connected to a master server at 127.21.111.62:34127
I20260812 06:16:23.408325 22226 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.408747 22226 heartbeater.cc:507] Master 127.21.111.62:34127 requested a full tablet report, sending...
I20260812 06:16:23.410207 21998 ts_manager.cc:194] Registered new tserver with Master: 52cb942d666f4f0094feb7a81086912a (127.21.111.1:33827)
I20260812 06:16:23.410403 21948 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014544591s
I20260812 06:16:23.412456 21998 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49052
I20260812 06:16:23.419412 21998 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49066:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:23.433444 22163 tablet_service.cc:1511] Processing CreateTablet for tablet 799c34c3b67f44d0964908854db2721a (DEFAULT_TABLE table=heavy-update-compaction-test [id=eb01ff57680e4399bc956f071e4848a0]), partition=
I20260812 06:16:23.433903 22163 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 799c34c3b67f44d0964908854db2721a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.436350 22253 tablet_bootstrap.cc:492] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Bootstrap starting.
I20260812 06:16:23.437426 22253 tablet_bootstrap.cc:654] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.438665 22253 tablet_bootstrap.cc:492] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: No bootstrap required, opened a new log
I20260812 06:16:23.438771 22253 ts_tablet_manager.cc:1403] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:23.439275 22253 raft_consensus.cc:359] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52cb942d666f4f0094feb7a81086912a" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 33827 } }
I20260812 06:16:23.439400 22253 raft_consensus.cc:385] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.439440 22253 raft_consensus.cc:740] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 52cb942d666f4f0094feb7a81086912a, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.439568 22253 consensus_queue.cc:260] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [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: "52cb942d666f4f0094feb7a81086912a" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 33827 } }
I20260812 06:16:23.439662 22253 raft_consensus.cc:399] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.439739 22253 raft_consensus.cc:493] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.439803 22253 raft_consensus.cc:3060] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.440685 22253 raft_consensus.cc:515] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52cb942d666f4f0094feb7a81086912a" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 33827 } }
I20260812 06:16:23.440831 22253 leader_election.cc:304] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [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: 52cb942d666f4f0094feb7a81086912a; no voters: 
I20260812 06:16:23.441025 22253 leader_election.cc:290] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.441123 22256 raft_consensus.cc:2804] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.441334 22253 ts_tablet_manager.cc:1434] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:23.441573 22226 heartbeater.cc:499] Master 127.21.111.62:34127 was elected leader, sending a full tablet report...
I20260812 06:16:23.441376 22256 raft_consensus.cc:697] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 1 LEADER]: Becoming Leader. State: Replica: 52cb942d666f4f0094feb7a81086912a, State: Running, Role: LEADER
I20260812 06:16:23.441934 22256 consensus_queue.cc:237] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [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: "52cb942d666f4f0094feb7a81086912a" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 33827 } }
I20260812 06:16:23.444586 21998 catalog_manager.cc:5719] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a reported cstate change: term changed from 0 to 1, leader changed from <none> to 52cb942d666f4f0094feb7a81086912a (127.21.111.1). New cstate: current_term: 1 leader_uuid: "52cb942d666f4f0094feb7a81086912a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52cb942d666f4f0094feb7a81086912a" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 33827 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.556069 21948 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.103s	user 0.011s	sys 0.022s
I20260812 06:16:23.646384 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushMRSOp(799c34c3b67f44d0964908854db2721a): perf score=10.125253
I20260812 06:16:23.783205 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushMRSOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.136s	user 0.109s	sys 0.024s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":217,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":937,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":28580,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":121,"threads_started":1,"update_count":1050}
I20260812 06:16:23.784695 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling LogGCOp(799c34c3b67f44d0964908854db2721a): free 8725963 bytes of WAL
I20260812 06:16:23.785089 22120 log_reader.cc:385] T 799c34c3b67f44d0964908854db2721a: removed 1 log segments from log reader
I20260812 06:16:23.785199 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000001 (ops 1-6)
I20260812 06:16:23.787410 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: LogGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:23.787820 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:23.804955 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.017s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.805481 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a): 8206537 bytes on disk
I20260812 06:16:23.806020 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:23.806406 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:23.815703 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:23.816082 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:23.937920 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20590457,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1281,"lbm_read_time_us":8159,"lbm_reads_lt_1ms":469,"lbm_write_time_us":21353,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":457,"threads_started":5,"update_count":2000}
I20260812 06:16:23.938462 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=7.149875
I20260812 06:16:23.975034 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.036s	user 0.007s	sys 0.023s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":16561,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:16:23.975616 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:23.990010 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:23.990577 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.083408 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.093s	user 0.080s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":5661,"lbm_reads_lt_1ms":368,"lbm_write_time_us":17068,"lbm_writes_lt_1ms":343,"mutex_wait_us":19,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":30976,"update_count":1500}
I20260812 06:16:24.084127 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:24.127012 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.043s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.127547 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:24.137460 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.137933 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.264802 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.127s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":132,"lbm_read_time_us":7272,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21108,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":46720,"update_count":2000}
I20260812 06:16:24.265628 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:24.307971 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.042s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14182,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.308449 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:24.318336 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.318861 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.434449 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.115s	user 0.075s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":878,"lbm_read_time_us":7553,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23091,"lbm_writes_lt_1ms":443,"mutex_wait_us":243,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.434918 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:24.478881 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.044s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":14918,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.479449 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:24.489756 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.490392 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.607545 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.117s	user 0.109s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590352,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":8901,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22206,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:16:24.608034 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:24.652994 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.045s	user 0.017s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13606,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:24.653566 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:24.663901 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.664378 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.795987 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.131s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":9973,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21393,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.796561 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:24.838061 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.041s	user 0.007s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14376,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.838547 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:24.854156 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.854702 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:24.980139 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.125s	user 0.103s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4297,"lbm_read_time_us":9524,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21652,"lbm_writes_lt_1ms":443,"mutex_wait_us":1907,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:16:24.980700 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:25.021297 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.040s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13398,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.021799 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:25.034118 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.034787 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushMRSOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:25.063246 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushMRSOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":292,"dirs.run_wall_time_us":1467,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1315,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:25.064260 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling LogGCOp(799c34c3b67f44d0964908854db2721a): free 124710286 bytes of WAL
I20260812 06:16:25.064517 22120 log_reader.cc:385] T 799c34c3b67f44d0964908854db2721a: removed 12 log segments from log reader
I20260812 06:16:25.064586 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000002 (ops 7-11)
I20260812 06:16:25.064630 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000003 (ops 12-16)
I20260812 06:16:25.064671 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000004 (ops 17-21)
I20260812 06:16:25.064702 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000005 (ops 22-26)
I20260812 06:16:25.064746 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000006 (ops 27-31)
I20260812 06:16:25.064783 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000007 (ops 32-36)
I20260812 06:16:25.064821 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000008 (ops 37-41)
I20260812 06:16:25.064857 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000009 (ops 42-46)
I20260812 06:16:25.064893 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000010 (ops 47-51)
I20260812 06:16:25.064929 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000011 (ops 52-56)
I20260812 06:16:25.064965 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000012 (ops 57-61)
I20260812 06:16:25.065001 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000013 (ops 62-66)
I20260812 06:16:25.086006 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: LogGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:25.086498 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=3.181125
I20260812 06:16:25.101481 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:25.101960 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a): 482 bytes on disk
I20260812 06:16:25.102398 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:25.102895 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:25.113286 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3759,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:25.113734 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:25.279363 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.165s	user 0.135s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795399,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1013,"lbm_read_time_us":10853,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31310,"lbm_writes_lt_1ms":643,"mutex_wait_us":244,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24960,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:16:25.279863 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:25.332324 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.052s	user 0.028s	sys 0.017s Metrics: {"bytes_written":16409916,"delete_count":0,"lbm_write_time_us":19507,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.332825 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:25.343585 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.344154 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:25.487882 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.144s	user 0.121s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692772,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":634,"lbm_read_time_us":8918,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26854,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:16:25.488523 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=11.118625
I20260812 06:16:25.538483 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":13374124,"delete_count":0,"lbm_write_time_us":16405,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":328,"reinsert_count":0,"update_count":1630}
I20260812 06:16:25.539055 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=5.165500
I20260812 06:16:25.562731 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.023s	user 0.006s	sys 0.011s Metrics: {"bytes_written":7138455,"delete_count":0,"lbm_write_time_us":7923,"lbm_writes_lt_1ms":177,"reinsert_count":0,"update_count":870}
I20260812 06:16:25.563169 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:25.704183 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.141s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692771,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":580,"lbm_read_time_us":8216,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26496,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:25.704778 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:25.748482 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.044s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16871,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.749029 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:25.764907 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.765502 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:25.917635 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.152s	user 0.110s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":9331,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28946,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:16:25.918648 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=12.110812
I20260812 06:16:25.950912 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.032s	user 0.024s	sys 0.005s Metrics: {"bytes_written":13579243,"delete_count":0,"lbm_write_time_us":13225,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:16:25.951428 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=1.196750
I20260812 06:16:25.964447 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3616,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:16:25.964919 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:26.102977 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.138s	user 0.082s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590321,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3424,"lbm_read_time_us":8225,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23072,"lbm_writes_lt_1ms":443,"mutex_wait_us":2798,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:16:26.103698 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=11.118625
I20260812 06:16:26.140128 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.036s	user 0.031s	sys 0.004s Metrics: {"bytes_written":13210025,"delete_count":0,"lbm_write_time_us":15258,"lbm_writes_lt_1ms":325,"reinsert_count":0,"update_count":1610}
I20260812 06:16:26.140601 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:26.158068 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.017s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3169,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:16:26.158658 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:26.178632 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.179373 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:26.355816 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.176s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":991,"lbm_read_time_us":13088,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25315,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:16:26.356366 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:26.403192 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.047s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.403769 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:26.414988 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.415769 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushMRSOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:26.449173 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushMRSOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2068,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:26.450101 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:26.464717 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.014s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.465219 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling LogGCOp(799c34c3b67f44d0964908854db2721a): free 136275205 bytes of WAL
I20260812 06:16:26.465481 22120 log_reader.cc:385] T 799c34c3b67f44d0964908854db2721a: removed 13 log segments from log reader
I20260812 06:16:26.465549 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000014 (ops 67-71)
I20260812 06:16:26.465600 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000015 (ops 72-76)
I20260812 06:16:26.465634 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000016 (ops 77-81)
I20260812 06:16:26.465668 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000017 (ops 82-86)
I20260812 06:16:26.465701 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000018 (ops 87-91)
I20260812 06:16:26.465732 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000019 (ops 92-96)
I20260812 06:16:26.465766 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000020 (ops 97-101)
I20260812 06:16:26.465796 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000021 (ops 102-106)
I20260812 06:16:26.465824 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000022 (ops 107-111)
I20260812 06:16:26.465847 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000023 (ops 112-116)
I20260812 06:16:26.465879 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000024 (ops 117-121)
I20260812 06:16:26.465910 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000025 (ops 122-126)
I20260812 06:16:26.465941 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000026 (ops 127-130)
I20260812 06:16:26.492098 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: LogGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:26.492560 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a): 482 bytes on disk
I20260812 06:16:26.493026 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:26.493670 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:26.691150 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.197s	user 0.135s	sys 0.054s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795287,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":877,"lbm_read_time_us":12529,"lbm_reads_lt_1ms":665,"lbm_write_time_us":32840,"lbm_writes_lt_1ms":643,"mutex_wait_us":320,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:16:26.691772 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=18.063937
I20260812 06:16:26.755627 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.064s	user 0.052s	sys 0.008s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":23772,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.756419 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:26.771260 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.771852 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:26.959015 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.187s	user 0.138s	sys 0.049s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795177,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":12931,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33163,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:16:26.959565 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:27.013449 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.054s	user 0.020s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.014008 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:27.029937 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.030516 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:27.198093 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.167s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":11366,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28614,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:16:27.198613 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:27.257560 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.059s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.258188 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:27.268497 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.269068 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:27.436532 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.167s	user 0.109s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":537,"lbm_read_time_us":12941,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27796,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:16:27.437079 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=11.118625
I20260812 06:16:27.472347 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.035s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14855,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:27.473042 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:27.497007 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.024s	user 0.008s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5439,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.497596 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:27.651482 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.154s	user 0.102s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":10201,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22348,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:16:27.652163 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:27.700237 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.048s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20491,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.700758 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:27.711580 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.712304 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:27.863992 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.151s	user 0.112s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692762,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":602,"lbm_read_time_us":9165,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28423,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:27.864538 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=14.095187
I20260812 06:16:27.911077 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.046s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17913,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.911620 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:27.928216 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.928992 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushMRSOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:27.965317 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushMRSOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.036s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1326,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1888,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:27.965998 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling LogGCOp(799c34c3b67f44d0964908854db2721a): free 128867720 bytes of WAL
I20260812 06:16:27.966228 22120 log_reader.cc:385] T 799c34c3b67f44d0964908854db2721a: removed 13 log segments from log reader
I20260812 06:16:27.966279 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000027 (ops 131-135)
I20260812 06:16:27.966310 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000028 (ops 136-140)
I20260812 06:16:27.966344 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000029 (ops 141-144)
I20260812 06:16:27.966369 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000030 (ops 145-149)
I20260812 06:16:27.966401 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000031 (ops 150-154)
I20260812 06:16:27.966432 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000032 (ops 155-158)
I20260812 06:16:27.966463 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000033 (ops 159-163)
I20260812 06:16:27.966495 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000034 (ops 164-168)
I20260812 06:16:27.966526 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000035 (ops 169-173)
I20260812 06:16:27.966558 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000036 (ops 174-178)
I20260812 06:16:27.966590 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000037 (ops 179-183)
I20260812 06:16:27.966621 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000038 (ops 184-188)
I20260812 06:16:27.966653 22120 log.cc:1079] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/799c34c3b67f44d0964908854db2721a/wal-000000039 (ops 189-192)
I20260812 06:16:27.990406 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: LogGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:27.990929 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a): 486 bytes on disk
I20260812 06:16:27.991448 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: UndoDeltaBlockGCOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.992066 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=3.181125
I20260812 06:16:28.008630 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4677002,"delete_count":0,"lbm_write_time_us":6586,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:16:28.009064 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=2.188937
I20260812 06:16:28.019289 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3293,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:16:28.019821 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a): perf score=1.000000
I20260812 06:16:28.173170 21948 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.617s	user 1.639s	sys 0.130s
I20260812 06:16:28.233886 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: MajorDeltaCompactionOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.214s	user 0.140s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897809,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13921,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34823,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3500}
I20260812 06:16:28.234378 22228 maintenance_manager.cc:419] P 52cb942d666f4f0094feb7a81086912a: Scheduling FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a): perf score=10.126437
I20260812 06:16:28.262297 21948 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.002s	sys 0.000s
I20260812 06:16:28.262979 21948 tablet_server.cc:179] TabletServer@127.21.111.1:0 shutting down...
I20260812 06:16:28.267962 22120 maintenance_manager.cc:643] P 52cb942d666f4f0094feb7a81086912a: FlushDeltaMemStoresOp(799c34c3b67f44d0964908854db2721a) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13150,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:16:28.268576 21948 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:28.268947 21948 tablet_replica.cc:333] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a: stopping tablet replica
I20260812 06:16:28.269164 21948 raft_consensus.cc:2243] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.269390 21948 raft_consensus.cc:2272] T 799c34c3b67f44d0964908854db2721a P 52cb942d666f4f0094feb7a81086912a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.284523 21948 tablet_server.cc:196] TabletServer@127.21.111.1:0 shutdown complete.
I20260812 06:16:28.298271 21948 master.cc:562] Master@127.21.111.62:34127 shutting down...
I20260812 06:16:28.302165 21948 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.302356 21948 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.302438 21948 tablet_replica.cc:333] T 00000000000000000000000000000000 P f703db55842b4ae1a10ea51ce88c8c7f: stopping tablet replica
I20260812 06:16:28.315079 21948 master.cc:584] Master@127.21.111.62:34127 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5105 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:28.396867 21948 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.111.62:43715
I20260812 06:16:28.397292 21948 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.399386 22279 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:28.399386 22281 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:28.399503 21948 server_base.cc:1061] running on GCE node
W20260812 06:16:28.399505 22285 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:28.399879 21948 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.399931 21948 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:28.399948 21948 hybrid_clock.cc:648] HybridClock initialized: now 1786515388399948 us; error 0 us; skew 500 ppm
I20260812 06:16:28.400823 21948 webserver.cc:533] Webserver started at http://127.21.111.62:44873/ using document root <none> and password file <none>
I20260812 06:16:28.400998 21948 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.401055 21948 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.401142 21948 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.401572 21948 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/master-0-root/instance:
uuid: "7133de28c600456f973b525e3fb4d766"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-nj21"
I20260812 06:16:28.403173 21948 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.404238 22294 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.404457 21948 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:16:28.404536 21948 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/master-0-root
uuid: "7133de28c600456f973b525e3fb4d766"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-nj21"
I20260812 06:16:28.404615 21948 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:28.416682 21948 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.417101 21948 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.421201 21948 rpc_server.cc:307] RPC server started. Bound to: 127.21.111.62:43715
I20260812 06:16:28.424387 22382 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.111.62:43715 every 8 connection(s)
I20260812 06:16:28.424674 22384 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:28.426599 22384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766: Bootstrap starting.
I20260812 06:16:28.427392 22384 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.428423 22384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766: No bootstrap required, opened a new log
I20260812 06:16:28.428812 22384 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7133de28c600456f973b525e3fb4d766" member_type: VOTER }
I20260812 06:16:28.428902 22384 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.428925 22384 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7133de28c600456f973b525e3fb4d766, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.429064 22384 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [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: "7133de28c600456f973b525e3fb4d766" member_type: VOTER }
I20260812 06:16:28.429138 22384 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.429159 22384 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.429252 22384 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.429952 22384 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7133de28c600456f973b525e3fb4d766" member_type: VOTER }
I20260812 06:16:28.430078 22384 leader_election.cc:304] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [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: 7133de28c600456f973b525e3fb4d766; no voters: 
I20260812 06:16:28.430243 22384 leader_election.cc:290] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.430354 22392 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.430570 22392 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 1 LEADER]: Becoming Leader. State: Replica: 7133de28c600456f973b525e3fb4d766, State: Running, Role: LEADER
I20260812 06:16:28.430693 22384 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:28.430716 22392 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [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: "7133de28c600456f973b525e3fb4d766" member_type: VOTER }
I20260812 06:16:28.431166 22394 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7133de28c600456f973b525e3fb4d766" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7133de28c600456f973b525e3fb4d766" member_type: VOTER } }
I20260812 06:16:28.431196 22398 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7133de28c600456f973b525e3fb4d766. Latest consensus state: current_term: 1 leader_uuid: "7133de28c600456f973b525e3fb4d766" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7133de28c600456f973b525e3fb4d766" member_type: VOTER } }
I20260812 06:16:28.431315 22394 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.431334 22398 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.431707 22404 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:28.432621 22404 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:28.432816 21948 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:28.434351 22404 catalog_manager.cc:1383] Generated new cluster ID: 80944b5395a64141b7f93a9b1c49e044
I20260812 06:16:28.434417 22404 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:28.442044 22404 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:28.442582 22404 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:28.447319 22404 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766: Generated new TSK 0
I20260812 06:16:28.447481 22404 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:28.448840 21948 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.450683 22420 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:28.450836 21948 server_base.cc:1061] running on GCE node
W20260812 06:16:28.450842 22421 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:28.450744 22425 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:28.451149 21948 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.451197 21948 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:28.451217 21948 hybrid_clock.cc:648] HybridClock initialized: now 1786515388451217 us; error 0 us; skew 500 ppm
I20260812 06:16:28.452076 21948 webserver.cc:533] Webserver started at http://127.21.111.1:39615/ using document root <none> and password file <none>
I20260812 06:16:28.452234 21948 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.452286 21948 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.452358 21948 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.452751 21948 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/instance:
uuid: "34e5397e36494fc5af73e1d06f7c39a9"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-nj21"
I20260812 06:16:28.454188 21948 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.455109 22432 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.455336 21948 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.455411 21948 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root
uuid: "34e5397e36494fc5af73e1d06f7c39a9"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-nj21"
I20260812 06:16:28.455482 21948 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:28.476029 21948 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.476449 21948 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.476768 21948 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:28.477242 21948 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:28.477280 21948 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.477326 21948 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:28.477355 21948 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.481442 21948 rpc_server.cc:307] RPC server started. Bound to: 127.21.111.1:37465
I20260812 06:16:28.483635 22534 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.111.1:37465 every 8 connection(s)
I20260812 06:16:28.490687 22536 heartbeater.cc:344] Connected to a master server at 127.21.111.62:43715
I20260812 06:16:28.490830 22536 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:28.491087 22536 heartbeater.cc:507] Master 127.21.111.62:43715 requested a full tablet report, sending...
I20260812 06:16:28.491798 22318 ts_manager.cc:194] Registered new tserver with Master: 34e5397e36494fc5af73e1d06f7c39a9 (127.21.111.1:37465)
I20260812 06:16:28.492048 21948 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009993843s
I20260812 06:16:28.492799 22318 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50074
I20260812 06:16:28.498809 22318 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50082:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:28.507097 22475 tablet_service.cc:1511] Processing CreateTablet for tablet f83773b9f16b4999a13e8e5751afd101 (DEFAULT_TABLE table=heavy-update-compaction-test [id=86becbfbcfbd4fe5805d6cb9d72b4e72]), partition=
I20260812 06:16:28.507365 22475 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f83773b9f16b4999a13e8e5751afd101. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:28.509303 22557 tablet_bootstrap.cc:492] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Bootstrap starting.
I20260812 06:16:28.510242 22557 tablet_bootstrap.cc:654] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.511269 22557 tablet_bootstrap.cc:492] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: No bootstrap required, opened a new log
I20260812 06:16:28.511343 22557 ts_tablet_manager.cc:1403] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:28.511790 22557 raft_consensus.cc:359] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34e5397e36494fc5af73e1d06f7c39a9" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 37465 } }
I20260812 06:16:28.511888 22557 raft_consensus.cc:385] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.511919 22557 raft_consensus.cc:740] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 34e5397e36494fc5af73e1d06f7c39a9, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.512064 22557 consensus_queue.cc:260] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [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: "34e5397e36494fc5af73e1d06f7c39a9" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 37465 } }
I20260812 06:16:28.512167 22557 raft_consensus.cc:399] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.512212 22557 raft_consensus.cc:493] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.512250 22557 raft_consensus.cc:3060] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.513070 22557 raft_consensus.cc:515] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34e5397e36494fc5af73e1d06f7c39a9" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 37465 } }
I20260812 06:16:28.513201 22557 leader_election.cc:304] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [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: 34e5397e36494fc5af73e1d06f7c39a9; no voters: 
I20260812 06:16:28.513379 22557 leader_election.cc:290] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.513482 22565 raft_consensus.cc:2804] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.513662 22557 ts_tablet_manager.cc:1434] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:28.513697 22565 raft_consensus.cc:697] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 1 LEADER]: Becoming Leader. State: Replica: 34e5397e36494fc5af73e1d06f7c39a9, State: Running, Role: LEADER
I20260812 06:16:28.513693 22536 heartbeater.cc:499] Master 127.21.111.62:43715 was elected leader, sending a full tablet report...
I20260812 06:16:28.513929 22565 consensus_queue.cc:237] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [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: "34e5397e36494fc5af73e1d06f7c39a9" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 37465 } }
I20260812 06:16:28.515209 22318 catalog_manager.cc:5719] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 34e5397e36494fc5af73e1d06f7c39a9 (127.21.111.1). New cstate: current_term: 1 leader_uuid: "34e5397e36494fc5af73e1d06f7c39a9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34e5397e36494fc5af73e1d06f7c39a9" member_type: VOTER last_known_addr { host: "127.21.111.1" port: 37465 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:28.573460 21948 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.015s	sys 0.008s
I20260812 06:16:28.734055 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushMRSOp(f83773b9f16b4999a13e8e5751afd101): perf score=20.047128
I20260812 06:16:28.907621 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushMRSOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.173s	user 0.114s	sys 0.052s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":817,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46406,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":856,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:16:28.908321 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling LogGCOp(f83773b9f16b4999a13e8e5751afd101): free 20743880 bytes of WAL
I20260812 06:16:28.908546 22438 log_reader.cc:385] T f83773b9f16b4999a13e8e5751afd101: removed 2 log segments from log reader
I20260812 06:16:28.908593 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000001 (ops 1-6)
I20260812 06:16:28.908622 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000002 (ops 7-11)
I20260812 06:16:28.912043 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: LogGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:28.912395 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101): 20513815 bytes on disk
I20260812 06:16:28.912842 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.913256 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:28.929562 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.930037 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:29.074079 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.144s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":8958,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22632,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":371,"threads_started":5,"update_count":2000}
I20260812 06:16:29.075276 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=12.110812
I20260812 06:16:29.110908 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.035s	user 0.015s	sys 0.017s Metrics: {"bytes_written":13579242,"delete_count":0,"lbm_write_time_us":14901,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:16:29.111532 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.196750
I20260812 06:16:29.125172 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3486,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:16:29.125777 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:29.275518 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.150s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713245,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":11112,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22606,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2000}
I20260812 06:16:29.276258 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:29.320847 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.044s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19959,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.321336 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:29.342200 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.021s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.342748 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:29.522677 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.180s	user 0.113s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":10799,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26540,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:29.523166 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:29.571599 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.048s	user 0.026s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17642,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.572146 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:29.582690 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.583302 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:29.748229 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.165s	user 0.116s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":10880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26174,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:16:29.748872 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=11.118625
I20260812 06:16:29.789815 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.041s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17312,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.790364 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:29.807564 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.017s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.808043 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:29.817735 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.818207 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:29.974141 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.156s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":868,"lbm_read_time_us":9517,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29584,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:29.974727 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=11.118625
I20260812 06:16:30.008844 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.034s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14020,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:30.009660 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.035022 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.025s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.035483 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.045377 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.045908 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushMRSOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:30.073755 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushMRSOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.028s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1292,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1491,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:30.074468 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling LogGCOp(f83773b9f16b4999a13e8e5751afd101): free 116849519 bytes of WAL
I20260812 06:16:30.074716 22438 log_reader.cc:385] T f83773b9f16b4999a13e8e5751afd101: removed 12 log segments from log reader
I20260812 06:16:30.074776 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000003 (ops 12-16)
I20260812 06:16:30.074818 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000004 (ops 17-20)
I20260812 06:16:30.074841 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000005 (ops 21-25)
I20260812 06:16:30.074870 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000006 (ops 26-30)
I20260812 06:16:30.074900 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000007 (ops 31-34)
I20260812 06:16:30.074941 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000008 (ops 35-39)
I20260812 06:16:30.074965 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000009 (ops 40-44)
I20260812 06:16:30.074985 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000010 (ops 45-49)
I20260812 06:16:30.075011 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000011 (ops 50-54)
I20260812 06:16:30.075035 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000012 (ops 55-58)
I20260812 06:16:30.075067 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000013 (ops 59-63)
I20260812 06:16:30.075098 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000014 (ops 64-68)
I20260812 06:16:30.100109 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: LogGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:30.100472 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101): 447 bytes on disk
I20260812 06:16:30.100880 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.101361 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=3.181125
I20260812 06:16:30.125603 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.024s	user 0.006s	sys 0.013s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4084,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:30.126410 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.138219 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4349,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.138737 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:30.368213 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.229s	user 0.148s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":326,"lbm_read_time_us":15387,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36124,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":583808,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:16:30.369010 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=15.087375
I20260812 06:16:30.417685 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.048s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":18374,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:30.418200 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.443346 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.025s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4897,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.443871 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.454185 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.454778 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:30.652594 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.198s	user 0.113s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1089,"lbm_read_time_us":13636,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31002,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27776,"update_count":3000}
I20260812 06:16:30.653146 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:30.698710 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.045s	user 0.018s	sys 0.023s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18453,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.699286 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.716789 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.717332 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:30.874500 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.157s	user 0.097s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":10308,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27099,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:30.875098 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:30.918354 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.043s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17192,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.918888 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:30.930038 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.930477 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:31.092042 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.161s	user 0.100s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":11108,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25577,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:16:31.092548 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:31.151087 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.058s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.151717 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:31.162367 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.162813 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:31.331877 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.169s	user 0.107s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":11530,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25592,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":33920,"update_count":2500}
I20260812 06:16:31.332427 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:31.391248 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.059s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.391862 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:31.402468 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.402958 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushMRSOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:31.447851 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushMRSOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.045s	user 0.022s	sys 0.008s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1413,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:31.448614 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling LogGCOp(f83773b9f16b4999a13e8e5751afd101): free 115943126 bytes of WAL
I20260812 06:16:31.448859 22438 log_reader.cc:385] T f83773b9f16b4999a13e8e5751afd101: removed 11 log segments from log reader
I20260812 06:16:31.448911 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000015 (ops 69-73)
I20260812 06:16:31.448947 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000016 (ops 74-78)
I20260812 06:16:31.448985 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000017 (ops 79-83)
I20260812 06:16:31.449021 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000018 (ops 84-88)
I20260812 06:16:31.449060 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000019 (ops 89-93)
I20260812 06:16:31.449096 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000020 (ops 94-98)
I20260812 06:16:31.449136 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000021 (ops 99-103)
I20260812 06:16:31.449173 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000022 (ops 104-108)
I20260812 06:16:31.449213 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000023 (ops 109-113)
I20260812 06:16:31.449250 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000024 (ops 114-118)
I20260812 06:16:31.449288 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000025 (ops 119-123)
I20260812 06:16:31.468356 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: LogGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:31.468783 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101): 447 bytes on disk
I20260812 06:16:31.469228 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101) 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:16:31.469786 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:31.492718 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.023s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.493142 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:31.503044 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.503494 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:31.741840 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.238s	user 0.168s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":763,"lbm_read_time_us":14398,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38259,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:16:31.742451 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=18.063937
I20260812 06:16:31.807446 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.065s	user 0.031s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26805,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.807996 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:31.820843 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4353,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.821465 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:32.022032 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.200s	user 0.120s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":14941,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31634,"lbm_writes_lt_1ms":643,"mutex_wait_us":329,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:16:32.022583 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:32.065769 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.043s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18654,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.066426 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:32.095474 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.029s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.096035 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:32.106026 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.106487 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:32.298090 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.191s	user 0.135s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":697,"lbm_read_time_us":13498,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30112,"lbm_writes_lt_1ms":643,"mutex_wait_us":358,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":3000}
I20260812 06:16:32.298696 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:32.352550 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.054s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17461,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.353204 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:32.369872 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.370406 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:32.540448 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.170s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":738,"lbm_read_time_us":12333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30256,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:16:32.540978 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:32.596211 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.055s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22253,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.596803 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:32.612823 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.016s	user 0.001s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.613425 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:32.776419 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.163s	user 0.094s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":11280,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25093,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":83328,"update_count":2500}
I20260812 06:16:32.776991 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:32.832737 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.056s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21922,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.833395 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=2.188937
I20260812 06:16:32.844204 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.844683 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushMRSOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:32.873925 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushMRSOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1161,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1877,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:32.874711 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101): 462 bytes on disk
I20260812 06:16:32.875175 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: UndoDeltaBlockGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.875880 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:33.042594 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.167s	user 0.113s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":11503,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26032,"lbm_writes_lt_1ms":543,"mutex_wait_us":104,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:33.043242 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling LogGCOp(f83773b9f16b4999a13e8e5751afd101): free 124257535 bytes of WAL
I20260812 06:16:33.043524 22438 log_reader.cc:385] T f83773b9f16b4999a13e8e5751afd101: removed 12 log segments from log reader
I20260812 06:16:33.043607 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000026 (ops 124-128)
I20260812 06:16:33.043704 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000027 (ops 129-133)
I20260812 06:16:33.043776 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000028 (ops 134-138)
I20260812 06:16:33.043840 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000029 (ops 139-143)
I20260812 06:16:33.043916 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000030 (ops 144-148)
I20260812 06:16:33.043973 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000031 (ops 149-153)
I20260812 06:16:33.044029 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000032 (ops 154-158)
I20260812 06:16:33.044090 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000033 (ops 159-163)
I20260812 06:16:33.044149 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000034 (ops 164-168)
I20260812 06:16:33.044205 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000035 (ops 169-173)
I20260812 06:16:33.044286 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000036 (ops 174-178)
I20260812 06:16:33.044365 22438 log.cc:1079] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: Deleting log segment in path: /tmp/dist-test-taskuxeCXq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383271138-21948-0/minicluster-data/ts-0-root/wals/f83773b9f16b4999a13e8e5751afd101/wal-000000037 (ops 179-182)
I20260812 06:16:33.069361 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: LogGCOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.026s	user 0.001s	sys 0.022s Metrics: {}
I20260812 06:16:33.069962 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=18.063937
I20260812 06:16:33.126610 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.056s	user 0.026s	sys 0.027s Metrics: {"bytes_written":20143102,"delete_count":0,"lbm_write_time_us":21045,"lbm_writes_lt_1ms":494,"reinsert_count":0,"update_count":2455}
I20260812 06:16:33.127193 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=3.181125
I20260812 06:16:33.144265 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.017s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4471882,"delete_count":0,"lbm_write_time_us":6670,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:16:33.144954 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:33.331658 21948 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.758s	user 1.709s	sys 0.177s
I20260812 06:16:33.338590 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.193s	user 0.112s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918107,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":14809,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31693,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:16:33.339093 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101): perf score=14.095187
I20260812 06:16:33.370276 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: FlushDeltaMemStoresOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.031s	user 0.015s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":14075,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.370811 22538 maintenance_manager.cc:419] P 34e5397e36494fc5af73e1d06f7c39a9: Scheduling MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101): perf score=1.000000
I20260812 06:16:33.410826 21948 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.001s	sys 0.000s
I20260812 06:16:33.411340 21948 tablet_server.cc:179] TabletServer@127.21.111.1:0 shutting down...
I20260812 06:16:33.499577 22438 maintenance_manager.cc:643] P 34e5397e36494fc5af73e1d06f7c39a9: MajorDeltaCompactionOp(f83773b9f16b4999a13e8e5751afd101) complete. Timing: real 0.129s	user 0.093s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1021,"lbm_read_time_us":6709,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23986,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2000}
I20260812 06:16:33.500146 21948 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:33.500334 21948 tablet_replica.cc:333] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9: stopping tablet replica
I20260812 06:16:33.500492 21948 raft_consensus.cc:2243] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.500648 21948 raft_consensus.cc:2272] T f83773b9f16b4999a13e8e5751afd101 P 34e5397e36494fc5af73e1d06f7c39a9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.514638 21948 tablet_server.cc:196] TabletServer@127.21.111.1:0 shutdown complete.
I20260812 06:16:33.540082 21948 master.cc:562] Master@127.21.111.62:43715 shutting down...
I20260812 06:16:33.543503 21948 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.543702 21948 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.543774 21948 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7133de28c600456f973b525e3fb4d766: stopping tablet replica
I20260812 06:16:33.556185 21948 master.cc:584] Master@127.21.111.62:43715 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5242 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10348 ms total)

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