[==========] 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:22.854440   964 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.241.62:37301
I20260812 06:16:22.855471   964 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:22.856067   964 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:22.862974   974 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:22.863003   975 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:22.863123   964 server_base.cc:1061] running on GCE node
W20260812 06:16:22.863281   977 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:22.863745   964 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:22.863837   964 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:22.863869   964 hybrid_clock.cc:648] HybridClock initialized: now 1786515382863867 us; error 0 us; skew 500 ppm
I20260812 06:16:22.865619   964 webserver.cc:533] Webserver started at http://127.0.241.62:33099/ using document root <none> and password file <none>
I20260812 06:16:22.866109   964 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:22.866164   964 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:22.866344   964 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:22.867923   964 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/master-0-root/instance:
uuid: "8e038816e369403b9632b63ef0c0e132"
format_stamp: "Formatted at 2026-08-12 06:16:22 on dist-test-slave-2kcd"
I20260812 06:16:22.871368   964 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:16:22.873422   984 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:22.874434   964 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:22.874526   964 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/master-0-root
uuid: "8e038816e369403b9632b63ef0c0e132"
format_stamp: "Formatted at 2026-08-12 06:16:22 on dist-test-slave-2kcd"
I20260812 06:16:22.874600   964 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-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:22.906068   964 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:22.906687   964 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:22.906826   964 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:22.914573   964 rpc_server.cc:307] RPC server started. Bound to: 127.0.241.62:37301
I20260812 06:16:22.914579  1079 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.241.62:37301 every 8 connection(s)
I20260812 06:16:22.916874  1080 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:22.922363  1080 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: Bootstrap starting.
I20260812 06:16:22.924723  1080 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:22.925665  1080 log.cc:826] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:22.927381  1080 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: No bootstrap required, opened a new log
I20260812 06:16:22.930158  1080 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER }
I20260812 06:16:22.930320  1080 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:22.930430  1080 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8e038816e369403b9632b63ef0c0e132, State: Initialized, Role: FOLLOWER
I20260812 06:16:22.931064  1080 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [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: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER }
I20260812 06:16:22.931226  1080 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:22.931324  1080 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:22.931473  1080 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:22.932281  1080 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER }
I20260812 06:16:22.932717  1080 leader_election.cc:304] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [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: 8e038816e369403b9632b63ef0c0e132; no voters: 
I20260812 06:16:22.933065  1080 leader_election.cc:290] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:22.933187  1088 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:22.933437  1088 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 1 LEADER]: Becoming Leader. State: Replica: 8e038816e369403b9632b63ef0c0e132, State: Running, Role: LEADER
I20260812 06:16:22.933902  1088 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [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: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER }
I20260812 06:16:22.934079  1080 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:22.935791  1091 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8e038816e369403b9632b63ef0c0e132. Latest consensus state: current_term: 1 leader_uuid: "8e038816e369403b9632b63ef0c0e132" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER } }
I20260812 06:16:22.935846  1090 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8e038816e369403b9632b63ef0c0e132" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e038816e369403b9632b63ef0c0e132" member_type: VOTER } }
I20260812 06:16:22.935901  1091 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:22.935935  1090 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:22.936254  1107 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:22.936571   964 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:22.938563  1107 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:22.943109  1107 catalog_manager.cc:1383] Generated new cluster ID: 3c90ae5cc1374fa8b7d8cae1c20e7c44
I20260812 06:16:22.943174  1107 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:22.953289  1107 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:22.954375  1107 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:22.968248  1107 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: Generated new TSK 0
I20260812 06:16:22.968969  1107 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.001792   964 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.004935  1123 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:23.005020  1125 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.005100  1129 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.005308   964 server_base.cc:1061] running on GCE node
I20260812 06:16:23.005602   964 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.005646   964 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.005662   964 hybrid_clock.cc:648] HybridClock initialized: now 1786515383005662 us; error 0 us; skew 500 ppm
I20260812 06:16:23.006594   964 webserver.cc:533] Webserver started at http://127.0.241.1:43195/ using document root <none> and password file <none>
I20260812 06:16:23.006800   964 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.006850   964 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.006951   964 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.007364   964 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/instance:
uuid: "b90f561d54254c649b298bb8d077b98b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-2kcd"
I20260812 06:16:23.009001   964 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:23.010000  1138 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.010282   964 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.010345   964 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root
uuid: "b90f561d54254c649b298bb8d077b98b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-2kcd"
I20260812 06:16:23.010430   964 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-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.022555   964 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.023021   964 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.023536   964 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.024431   964 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.024494   964 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.024566   964 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.024626   964 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.032994   964 rpc_server.cc:307] RPC server started. Bound to: 127.0.241.1:41879
I20260812 06:16:23.033021  1257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.241.1:41879 every 8 connection(s)
I20260812 06:16:23.045375  1258 heartbeater.cc:344] Connected to a master server at 127.0.241.62:37301
I20260812 06:16:23.045636  1258 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.046132  1258 heartbeater.cc:507] Master 127.0.241.62:37301 requested a full tablet report, sending...
I20260812 06:16:23.047730  1016 ts_manager.cc:194] Registered new tserver with Master: b90f561d54254c649b298bb8d077b98b (127.0.241.1:41879)
I20260812 06:16:23.048321   964 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014553739s
I20260812 06:16:23.049458  1016 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59008
I20260812 06:16:23.059984  1016 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59020:
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.079135  1191 tablet_service.cc:1511] Processing CreateTablet for tablet 2b0a493956a84a5bbfa8df31fea42d9e (DEFAULT_TABLE table=heavy-update-compaction-test [id=2f154d1b0e8240c896a654e88e6f6c96]), partition=
I20260812 06:16:23.079631  1191 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2b0a493956a84a5bbfa8df31fea42d9e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.082813  1276 tablet_bootstrap.cc:492] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Bootstrap starting.
I20260812 06:16:23.085233  1276 tablet_bootstrap.cc:654] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.087337  1276 tablet_bootstrap.cc:492] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: No bootstrap required, opened a new log
I20260812 06:16:23.087491  1276 ts_tablet_manager.cc:1403] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Time spent bootstrapping tablet: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:16:23.088397  1276 raft_consensus.cc:359] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b90f561d54254c649b298bb8d077b98b" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 41879 } }
I20260812 06:16:23.088572  1276 raft_consensus.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.088644  1276 raft_consensus.cc:740] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b90f561d54254c649b298bb8d077b98b, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.088824  1276 consensus_queue.cc:260] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [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: "b90f561d54254c649b298bb8d077b98b" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 41879 } }
I20260812 06:16:23.088932  1276 raft_consensus.cc:399] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.089023  1276 raft_consensus.cc:493] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.089118  1276 raft_consensus.cc:3060] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.091465  1276 raft_consensus.cc:515] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b90f561d54254c649b298bb8d077b98b" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 41879 } }
I20260812 06:16:23.091610  1276 leader_election.cc:304] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [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: b90f561d54254c649b298bb8d077b98b; no voters: 
I20260812 06:16:23.091929  1276 leader_election.cc:290] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.092113  1278 raft_consensus.cc:2804] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.092334  1276 ts_tablet_manager.cc:1434] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Time spent starting tablet: real 0.005s	user 0.005s	sys 0.000s
I20260812 06:16:23.092438  1278 raft_consensus.cc:697] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 1 LEADER]: Becoming Leader. State: Replica: b90f561d54254c649b298bb8d077b98b, State: Running, Role: LEADER
I20260812 06:16:23.092643  1278 consensus_queue.cc:237] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [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: "b90f561d54254c649b298bb8d077b98b" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 41879 } }
I20260812 06:16:23.092685  1258 heartbeater.cc:499] Master 127.0.241.62:37301 was elected leader, sending a full tablet report...
I20260812 06:16:23.095750  1016 catalog_manager.cc:5719] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b reported cstate change: term changed from 0 to 1, leader changed from <none> to b90f561d54254c649b298bb8d077b98b (127.0.241.1). New cstate: current_term: 1 leader_uuid: "b90f561d54254c649b298bb8d077b98b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b90f561d54254c649b298bb8d077b98b" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 41879 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.208189   964 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.101s	user 0.014s	sys 0.045s
I20260812 06:16:23.284422  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=7.148690
I20260812 06:16:23.409307  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.124s	user 0.079s	sys 0.041s Metrics: {"bytes_written":8410200,"cfile_init":1,"compiler_manager_pool.queue_time_us":15117,"delete_count":0,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":964,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":24783,"lbm_writes_lt_1ms":372,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":123776,"thread_start_us":106,"threads_started":1,"update_count":1025}
I20260812 06:16:23.410463  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e): free 8725963 bytes of WAL
I20260812 06:16:23.410816  1144 log_reader.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e: removed 1 log segments from log reader
I20260812 06:16:23.410902  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000001 (ops 1-6)
I20260812 06:16:23.413514  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:23.413844  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e): 4514099 bytes on disk
I20260812 06:16:23.414548  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:16:23.415050  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:23.436273  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:16:23.436820  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:23.451575  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.452167  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:23.613673  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.161s	user 0.108s	sys 0.053s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20180209,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":972,"lbm_read_time_us":9797,"lbm_reads_lt_1ms":459,"lbm_write_time_us":45648,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":317,"threads_started":5,"update_count":1950}
I20260812 06:16:23.614413  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:23.654229  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16875,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:23.654764  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:23.669860  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.670359  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:23.795207  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.125s	user 0.109s	sys 0.015s 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":263,"lbm_read_time_us":8190,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24899,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:16:23.795847  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:23.852110  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.056s	user 0.013s	sys 0.034s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17421,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:23.852706  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:23.863669  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.864125  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:24.008988  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.145s	user 0.097s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":11065,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23421,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.009745  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:24.056439  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.047s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17541,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.056957  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.068207  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.068699  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:24.190627  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.122s	user 0.095s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":7877,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26350,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:16:24.191166  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:24.241649  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.050s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18520,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.242156  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.256414  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.257229  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:24.396963  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.140s	user 0.105s	sys 0.028s 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":1540,"lbm_read_time_us":9839,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28078,"lbm_writes_lt_1ms":443,"mutex_wait_us":546,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:16:24.397621  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=11.118625
I20260812 06:16:24.438915  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.041s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14876,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:24.439419  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.463049  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.023s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5171,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.463603  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.473773  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.474185  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:24.671453  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.197s	user 0.142s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":181,"lbm_read_time_us":13535,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34117,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:16:24.672170  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:24.729192  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20251,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:24.729702  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.740159  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.740576  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:24.784405  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.044s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1437,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1478,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:24.785344  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e): free 124257189 bytes of WAL
I20260812 06:16:24.785634  1144 log_reader.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e: removed 12 log segments from log reader
I20260812 06:16:24.785696  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000002 (ops 7-11)
I20260812 06:16:24.785737  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000003 (ops 12-16)
I20260812 06:16:24.785769  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000004 (ops 17-21)
I20260812 06:16:24.785792  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000005 (ops 22-26)
I20260812 06:16:24.785822  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000006 (ops 27-31)
I20260812 06:16:24.785846  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000007 (ops 32-36)
I20260812 06:16:24.785873  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000008 (ops 37-41)
I20260812 06:16:24.785905  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000009 (ops 42-46)
I20260812 06:16:24.785938  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000010 (ops 47-51)
I20260812 06:16:24.785970  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000011 (ops 52-56)
I20260812 06:16:24.786000  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000012 (ops 57-60)
I20260812 06:16:24.786031  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000013 (ops 61-65)
I20260812 06:16:24.816435  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:24.816963  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.843005  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.026s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.843492  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:24.853866  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.854259  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:25.060813  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.206s	user 0.134s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897820,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":543,"lbm_read_time_us":16438,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37298,"lbm_writes_lt_1ms":743,"mutex_wait_us":84,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:16:25.063623  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:25.122470  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.059s	user 0.030s	sys 0.026s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":26288,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.123091  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.142616  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.143064  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.153635  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.154054  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:25.325678  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.171s	user 0.140s	sys 0.031s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795286,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":262,"lbm_read_time_us":13087,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35007,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":38272,"update_count":3000}
I20260812 06:16:25.326259  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e): 463 bytes on disk
I20260812 06:16:25.326792  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:16:25.327324  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:25.381546  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.054s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.382052  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.405663  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.023s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":4426,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:16:25.406106  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.416404  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:16:25.416932  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:25.583742  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.167s	user 0.126s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795290,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":171,"lbm_read_time_us":12682,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36018,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":3000}
I20260812 06:16:25.584232  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:25.631237  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.047s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21215,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.631999  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.646277  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.646837  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:25.813894  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.167s	user 0.113s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692760,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1262,"lbm_read_time_us":9106,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32483,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:16:25.814630  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:25.874528  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.060s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.875007  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:25.886538  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.887036  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:26.068964  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.182s	user 0.109s	sys 0.067s 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":609,"lbm_read_time_us":12066,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32966,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:16:26.069705  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:26.124912  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.055s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:16:26.125455  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:26.137310  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.137795  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:26.173925  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.036s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1561,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1619,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:26.174641  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e): free 112239323 bytes of WAL
I20260812 06:16:26.174870  1144 log_reader.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e: removed 11 log segments from log reader
I20260812 06:16:26.174916  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000014 (ops 66-70)
I20260812 06:16:26.174947  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000015 (ops 71-75)
I20260812 06:16:26.175012  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000016 (ops 76-80)
I20260812 06:16:26.175056  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000017 (ops 81-85)
I20260812 06:16:26.175119  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000018 (ops 86-90)
I20260812 06:16:26.175159  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000019 (ops 91-94)
I20260812 06:16:26.175199  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000020 (ops 95-99)
I20260812 06:16:26.175242  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000021 (ops 100-104)
I20260812 06:16:26.175284  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000022 (ops 105-109)
I20260812 06:16:26.175324  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000023 (ops 110-114)
I20260812 06:16:26.175364  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000024 (ops 115-119)
I20260812 06:16:26.199044  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:26.199621  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e): 462 bytes on disk
I20260812 06:16:26.200192  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:16:26.200877  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:26.216936  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.217319  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:26.227267  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.227653  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:26.455837  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.228s	user 0.171s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897822,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":692,"lbm_read_time_us":18771,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38695,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:16:26.456626  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=18.063937
I20260812 06:16:26.512306  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.055s	user 0.029s	sys 0.023s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24148,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.513010  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:26.525048  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.525478  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:26.696132  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.170s	user 0.146s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795172,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":12149,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34675,"lbm_writes_lt_1ms":643,"mutex_wait_us":146,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":3000}
I20260812 06:16:26.696898  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:26.743382  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.046s	user 0.035s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20197,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.744086  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:26.757489  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.758038  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:26.927649  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.169s	user 0.119s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692760,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":10905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30820,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:16:26.928246  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=14.095187
I20260812 06:16:26.976411  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.048s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21223,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.976976  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:27.119228  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.142s	user 0.097s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590229,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":138,"lbm_read_time_us":8752,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26289,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:16:27.119933  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:27.156195  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.156769  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.177784  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.021s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.178345  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:27.303619  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.125s	user 0.097s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":790,"lbm_read_time_us":9356,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24082,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:16:27.304302  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:27.342175  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.038s	user 0.032s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16199,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.342767  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.358248  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.359241  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:27.491257  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.132s	user 0.084s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":10251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25880,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:27.492023  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=10.126437
I20260812 06:16:27.534818  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.043s	user 0.020s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20401,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.535315  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.553005  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.017s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.553788  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:27.606698  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushMRSOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.053s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1530,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1871,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:27.607429  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e): free 120553595 bytes of WAL
I20260812 06:16:27.607666  1144 log_reader.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e: removed 12 log segments from log reader
I20260812 06:16:27.607730  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000025 (ops 120-124)
I20260812 06:16:27.607785  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000026 (ops 125-128)
I20260812 06:16:27.607839  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000027 (ops 129-133)
I20260812 06:16:27.607882  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000028 (ops 134-138)
I20260812 06:16:27.607919  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000029 (ops 139-143)
I20260812 06:16:27.607959  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000030 (ops 144-148)
I20260812 06:16:27.608006  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000031 (ops 149-152)
I20260812 06:16:27.608044  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000032 (ops 153-157)
I20260812 06:16:27.608083  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000033 (ops 158-162)
I20260812 06:16:27.608127  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000034 (ops 163-167)
I20260812 06:16:27.608165  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000035 (ops 168-172)
I20260812 06:16:27.608203  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000036 (ops 173-177)
I20260812 06:16:27.636337  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:27.636770  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=7.149875
I20260812 06:16:27.657652  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.021s	user 0.019s	sys 0.001s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8723,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:27.658142  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e): free 12018006 bytes of WAL
I20260812 06:16:27.658340  1144 log_reader.cc:385] T 2b0a493956a84a5bbfa8df31fea42d9e: removed 1 log segments from log reader
I20260812 06:16:27.658401  1144 log.cc:1079] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382843482-964-0/minicluster-data/ts-0-root/wals/2b0a493956a84a5bbfa8df31fea42d9e/wal-000000037 (ops 178-182)
I20260812 06:16:27.660873  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: LogGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:27.661343  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e): 472 bytes on disk
I20260812 06:16:27.661993  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: UndoDeltaBlockGCOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.662869  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.687593  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.025s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:16:27.688071  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.698225  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.698691  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:27.913107  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.214s	user 0.165s	sys 0.042s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37000345,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":739,"lbm_read_time_us":15103,"lbm_reads_lt_1ms":875,"lbm_write_time_us":40355,"lbm_writes_lt_1ms":843,"mutex_wait_us":80,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":101,"threads_started":1,"update_count":4000}
I20260812 06:16:27.913703  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=18.063937
I20260812 06:16:27.973399  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.060s	user 0.048s	sys 0.010s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26755,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:27.973963  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=2.188937
I20260812 06:16:27.990295  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: FlushDeltaMemStoresOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.990806  1259 maintenance_manager.cc:419] P b90f561d54254c649b298bb8d077b98b: Scheduling MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e): perf score=1.000000
I20260812 06:16:28.023041   964 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.815s	user 1.820s	sys 0.130s
I20260812 06:16:28.078871   964 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.002s	sys 0.000s
I20260812 06:16:28.079494   964 tablet_server.cc:179] TabletServer@127.0.241.1:0 shutting down...
I20260812 06:16:28.146597  1144 maintenance_manager.cc:643] P b90f561d54254c649b298bb8d077b98b: MajorDeltaCompactionOp(2b0a493956a84a5bbfa8df31fea42d9e) complete. Timing: real 0.156s	user 0.109s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795173,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1153,"lbm_read_time_us":13388,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30246,"lbm_writes_lt_1ms":643,"mutex_wait_us":94,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:16:28.147282   964 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:28.147688   964 tablet_replica.cc:333] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b: stopping tablet replica
I20260812 06:16:28.147941   964 raft_consensus.cc:2243] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.148190   964 raft_consensus.cc:2272] T 2b0a493956a84a5bbfa8df31fea42d9e P b90f561d54254c649b298bb8d077b98b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.164513   964 tablet_server.cc:196] TabletServer@127.0.241.1:0 shutdown complete.
I20260812 06:16:28.199932   964 master.cc:562] Master@127.0.241.62:37301 shutting down...
I20260812 06:16:28.203953   964 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.204159   964 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.204267   964 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8e038816e369403b9632b63ef0c0e132: stopping tablet replica
I20260812 06:16:28.216831   964 master.cc:584] Master@127.0.241.62:37301 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5461 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:28.315544   964 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.241.62:43033
I20260812 06:16:28.315980   964 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.318226  1308 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.318326   964 server_base.cc:1061] running on GCE node
W20260812 06:16:28.318370  1311 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:28.318372  1309 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.318768   964 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.318814   964 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.318830   964 hybrid_clock.cc:648] HybridClock initialized: now 1786515388318830 us; error 0 us; skew 500 ppm
I20260812 06:16:28.319727   964 webserver.cc:533] Webserver started at http://127.0.241.62:37027/ using document root <none> and password file <none>
I20260812 06:16:28.319903   964 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.319983   964 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.320068   964 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.320485   964 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/master-0-root/instance:
uuid: "36e3597417064fa88ba6873affe67c4a"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-2kcd"
I20260812 06:16:28.322203   964 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.323144  1326 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.323408   964 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.323500   964 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/master-0-root
uuid: "36e3597417064fa88ba6873affe67c4a"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-2kcd"
I20260812 06:16:28.323593   964 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-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.330703   964 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.331040   964 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.335093   964 rpc_server.cc:307] RPC server started. Bound to: 127.0.241.62:43033
I20260812 06:16:28.337991  1421 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.343092  1418 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.241.62:43033 every 8 connection(s)
I20260812 06:16:28.346285  1421 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a: Bootstrap starting.
I20260812 06:16:28.347199  1421 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.348249  1421 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a: No bootstrap required, opened a new log
I20260812 06:16:28.348680  1421 raft_consensus.cc:359] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER }
I20260812 06:16:28.348769  1421 raft_consensus.cc:385] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.348865  1421 raft_consensus.cc:740] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 36e3597417064fa88ba6873affe67c4a, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.349058  1421 consensus_queue.cc:260] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [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: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER }
I20260812 06:16:28.349131  1421 raft_consensus.cc:399] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.349188  1421 raft_consensus.cc:493] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.349248  1421 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.349928  1421 raft_consensus.cc:515] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER }
I20260812 06:16:28.350052  1421 leader_election.cc:304] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [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: 36e3597417064fa88ba6873affe67c4a; no voters: 
I20260812 06:16:28.350299  1421 leader_election.cc:290] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.350457  1424 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.350703  1424 raft_consensus.cc:697] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 1 LEADER]: Becoming Leader. State: Replica: 36e3597417064fa88ba6873affe67c4a, State: Running, Role: LEADER
I20260812 06:16:28.350766  1421 sys_catalog.cc:565] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:28.350893  1424 consensus_queue.cc:237] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [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: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER }
I20260812 06:16:28.351359  1425 sys_catalog.cc:455] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "36e3597417064fa88ba6873affe67c4a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER } }
I20260812 06:16:28.351401  1426 sys_catalog.cc:455] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 36e3597417064fa88ba6873affe67c4a. Latest consensus state: current_term: 1 leader_uuid: "36e3597417064fa88ba6873affe67c4a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36e3597417064fa88ba6873affe67c4a" member_type: VOTER } }
I20260812 06:16:28.351475  1425 sys_catalog.cc:458] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.351488  1426 sys_catalog.cc:458] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.352016  1436 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:28.352985  1436 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:28.353143   964 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:28.354914  1436 catalog_manager.cc:1383] Generated new cluster ID: f58c0154fec84f5596f4c76def0bfc93
I20260812 06:16:28.354970  1436 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:28.361202  1436 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:28.361725  1436 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:28.371275  1436 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a: Generated new TSK 0
I20260812 06:16:28.371477  1436 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:28.385551   964 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.387797  1460 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.387858   964 server_base.cc:1061] running on GCE node
W20260812 06:16:28.387809  1461 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.387878  1465 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.388226   964 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.388270   964 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.388286   964 hybrid_clock.cc:648] HybridClock initialized: now 1786515388388286 us; error 0 us; skew 500 ppm
I20260812 06:16:28.389163   964 webserver.cc:533] Webserver started at http://127.0.241.1:39641/ using document root <none> and password file <none>
I20260812 06:16:28.389338   964 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.389387   964 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.389448   964 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.389788   964 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/instance:
uuid: "ea58db517f9a4841a0955c93ac24ea5e"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-2kcd"
I20260812 06:16:28.391223   964 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.392129  1477 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.392361   964 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.392432   964 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root
uuid: "ea58db517f9a4841a0955c93ac24ea5e"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-2kcd"
I20260812 06:16:28.392532   964 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-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.406414   964 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.406838   964 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.407155   964 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:28.407637   964 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:28.407698   964 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.407758   964 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:28.407809   964 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.412144   964 rpc_server.cc:307] RPC server started. Bound to: 127.0.241.1:36309
I20260812 06:16:28.413683  1600 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.241.1:36309 every 8 connection(s)
I20260812 06:16:28.420825  1602 heartbeater.cc:344] Connected to a master server at 127.0.241.62:43033
I20260812 06:16:28.420953  1602 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:28.421152  1602 heartbeater.cc:507] Master 127.0.241.62:43033 requested a full tablet report, sending...
I20260812 06:16:28.421761  1366 ts_manager.cc:194] Registered new tserver with Master: ea58db517f9a4841a0955c93ac24ea5e (127.0.241.1:36309)
I20260812 06:16:28.422027   964 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008985486s
I20260812 06:16:28.422591  1366 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45464
I20260812 06:16:28.429111  1366 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45478:
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.437628  1535 tablet_service.cc:1511] Processing CreateTablet for tablet a877832273b041689e98e6af9af2e40f (DEFAULT_TABLE table=heavy-update-compaction-test [id=06802caf133d424e800c0cdd1b388233]), partition=
I20260812 06:16:28.437923  1535 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a877832273b041689e98e6af9af2e40f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:28.440058  1631 tablet_bootstrap.cc:492] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Bootstrap starting.
I20260812 06:16:28.440965  1631 tablet_bootstrap.cc:654] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.441969  1631 tablet_bootstrap.cc:492] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: No bootstrap required, opened a new log
I20260812 06:16:28.442041  1631 ts_tablet_manager.cc:1403] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:16:28.442422  1631 raft_consensus.cc:359] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea58db517f9a4841a0955c93ac24ea5e" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 36309 } }
I20260812 06:16:28.442508  1631 raft_consensus.cc:385] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.442531  1631 raft_consensus.cc:740] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ea58db517f9a4841a0955c93ac24ea5e, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.442662  1631 consensus_queue.cc:260] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [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: "ea58db517f9a4841a0955c93ac24ea5e" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 36309 } }
I20260812 06:16:28.442762  1631 raft_consensus.cc:399] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.442814  1631 raft_consensus.cc:493] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.442868  1631 raft_consensus.cc:3060] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.443717  1631 raft_consensus.cc:515] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea58db517f9a4841a0955c93ac24ea5e" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 36309 } }
I20260812 06:16:28.443833  1631 leader_election.cc:304] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [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: ea58db517f9a4841a0955c93ac24ea5e; no voters: 
I20260812 06:16:28.443985  1631 leader_election.cc:290] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.444118  1634 raft_consensus.cc:2804] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.444334  1602 heartbeater.cc:499] Master 127.0.241.62:43033 was elected leader, sending a full tablet report...
I20260812 06:16:28.444337  1634 raft_consensus.cc:697] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 1 LEADER]: Becoming Leader. State: Replica: ea58db517f9a4841a0955c93ac24ea5e, State: Running, Role: LEADER
I20260812 06:16:28.444339  1631 ts_tablet_manager.cc:1434] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:28.444496  1634 consensus_queue.cc:237] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [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: "ea58db517f9a4841a0955c93ac24ea5e" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 36309 } }
I20260812 06:16:28.445803  1366 catalog_manager.cc:5719] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e reported cstate change: term changed from 0 to 1, leader changed from <none> to ea58db517f9a4841a0955c93ac24ea5e (127.0.241.1). New cstate: current_term: 1 leader_uuid: "ea58db517f9a4841a0955c93ac24ea5e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea58db517f9a4841a0955c93ac24ea5e" member_type: VOTER last_known_addr { host: "127.0.241.1" port: 36309 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:28.504746   964 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.004s
I20260812 06:16:28.664090  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushMRSOp(a877832273b041689e98e6af9af2e40f): perf score=19.054940
I20260812 06:16:28.821143  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushMRSOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.157s	user 0.125s	sys 0.031s Metrics: {"bytes_written":12963880,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1032,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38793,"lbm_writes_lt_1ms":783,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":768,"update_count":1580}
I20260812 06:16:28.821883  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling LogGCOp(a877832273b041689e98e6af9af2e40f): free 20743880 bytes of WAL
I20260812 06:16:28.822129  1490 log_reader.cc:385] T a877832273b041689e98e6af9af2e40f: removed 2 log segments from log reader
I20260812 06:16:28.822201  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000001 (ops 1-6)
I20260812 06:16:28.822254  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000002 (ops 7-11)
I20260812 06:16:28.826956  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: LogGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:28.827346  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f): 16821648 bytes on disk
I20260812 06:16:28.827795  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f) 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:28.828261  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=3.181125
I20260812 06:16:28.844481  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":5251345,"delete_count":0,"lbm_write_time_us":6520,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:16:28.845129  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:28.855131  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":2678,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:16:28.855526  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:29.023734  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.168s	user 0.101s	sys 0.062s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405517,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":536,"lbm_read_time_us":12588,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28511,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":353,"threads_started":5,"update_count":2450}
I20260812 06:16:29.024344  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:29.079030  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.054s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21119,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.079514  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:29.090448  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.091130  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:29.263146  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.172s	user 0.121s	sys 0.044s 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":407,"lbm_read_time_us":11636,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30338,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:16:29.263741  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:29.320844  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.057s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23207,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.321420  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:29.481540  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.160s	user 0.101s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":224,"lbm_read_time_us":10919,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26804,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:16:29.482369  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=11.118625
I20260812 06:16:29.520891  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.038s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16208,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.521402  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:29.533990  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.534610  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:29.661746  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.127s	user 0.095s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":7779,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24722,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:16:29.662546  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=11.118625
I20260812 06:16:29.701164  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.038s	user 0.010s	sys 0.028s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17013,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.701696  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:29.719238  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5531,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.719724  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:29.847298  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.127s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":80,"lbm_read_time_us":7849,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25400,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.848127  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=10.126437
I20260812 06:16:29.885586  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.037s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16696,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:29.886068  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:29.897171  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.897774  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:30.020737  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.123s	user 0.082s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":526,"lbm_read_time_us":9621,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22282,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:30.021610  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=10.126437
I20260812 06:16:30.071614  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.050s	user 0.028s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17812,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.072187  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.082949  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.083455  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushMRSOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:30.124362  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushMRSOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.041s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":151,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2016,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:30.125253  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling LogGCOp(a877832273b041689e98e6af9af2e40f): free 120100342 bytes of WAL
I20260812 06:16:30.125519  1490 log_reader.cc:385] T a877832273b041689e98e6af9af2e40f: removed 12 log segments from log reader
I20260812 06:16:30.125588  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000003 (ops 12-16)
I20260812 06:16:30.125640  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000004 (ops 17-21)
I20260812 06:16:30.125676  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000005 (ops 22-26)
I20260812 06:16:30.125715  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000006 (ops 27-30)
I20260812 06:16:30.125751  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000007 (ops 31-35)
I20260812 06:16:30.125793  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000008 (ops 36-40)
I20260812 06:16:30.125828  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000009 (ops 41-44)
I20260812 06:16:30.125864  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000010 (ops 45-49)
I20260812 06:16:30.125911  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000011 (ops 50-54)
I20260812 06:16:30.125948  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000012 (ops 55-59)
I20260812 06:16:30.125985  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000013 (ops 60-64)
I20260812 06:16:30.126021  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000014 (ops 65-68)
I20260812 06:16:30.153059  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: LogGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:30.153515  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.171921  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.018s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.172494  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.182704  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.183377  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f): 462 bytes on disk
I20260812 06:16:30.183933  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f) 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:30.184540  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:30.409508  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.225s	user 0.158s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918333,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":339,"lbm_read_time_us":15022,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34927,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":107,"threads_started":1,"update_count":3000}
I20260812 06:16:30.410385  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=18.063937
I20260812 06:16:30.475417  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.065s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25652,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:30.475917  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.487353  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.487960  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:30.686885  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.199s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":482,"lbm_read_time_us":13109,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33932,"lbm_writes_lt_1ms":643,"mutex_wait_us":286,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:16:30.687559  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=15.087375
I20260812 06:16:30.738102  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.050s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21814,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:30.738758  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.764422  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.025s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4717,"lbm_writes_lt_1ms":93,"mutex_wait_us":2,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.765002  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:30.779747  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.780287  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:30.988895  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.208s	user 0.129s	sys 0.079s 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":155,"lbm_read_time_us":14763,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35821,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":3000}
I20260812 06:16:30.989689  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:31.045061  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.055s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24577,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.045660  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.056579  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.057147  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:31.230587  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.173s	user 0.114s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":11425,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31458,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:16:31.231329  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:31.288254  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.057s	user 0.026s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21014,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.288851  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.299710  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.300477  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:31.471235  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.170s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":12572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29575,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:16:31.471992  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:31.535776  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.064s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21569,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.536315  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.547792  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.548348  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushMRSOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:31.595508  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushMRSOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.047s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1527,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1609,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:31.596199  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling LogGCOp(a877832273b041689e98e6af9af2e40f): free 117302571 bytes of WAL
I20260812 06:16:31.596449  1490 log_reader.cc:385] T a877832273b041689e98e6af9af2e40f: removed 12 log segments from log reader
I20260812 06:16:31.596527  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000015 (ops 69-73)
I20260812 06:16:31.596578  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000016 (ops 74-78)
I20260812 06:16:31.596637  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000017 (ops 79-83)
I20260812 06:16:31.596681  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000018 (ops 84-88)
I20260812 06:16:31.596721  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000019 (ops 89-92)
I20260812 06:16:31.596761  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000020 (ops 93-97)
I20260812 06:16:31.596825  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000021 (ops 98-102)
I20260812 06:16:31.596866  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000022 (ops 103-107)
I20260812 06:16:31.596906  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000023 (ops 108-112)
I20260812 06:16:31.596946  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000024 (ops 113-116)
I20260812 06:16:31.596984  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000025 (ops 117-121)
I20260812 06:16:31.597023  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000026 (ops 122-126)
I20260812 06:16:31.623731  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: LogGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:16:31.624231  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.639535  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.015s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4364,"lbm_writes_lt_1ms":106,"mutex_wait_us":776,"reinsert_count":0,"update_count":515}
I20260812 06:16:31.639950  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f): 462 bytes on disk
I20260812 06:16:31.640331  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f) 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:31.640877  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.650907  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:16:31.651335  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:31.887873  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.236s	user 0.154s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":174,"lbm_read_time_us":17144,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39091,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11776,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:16:31.888618  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=18.063937
I20260812 06:16:31.947409  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.058s	user 0.036s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25211,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.948037  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:31.960076  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.960544  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:32.135267  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.175s	user 0.149s	sys 0.023s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":13969,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30845,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:16:32.136183  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:32.188740  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.052s	user 0.044s	sys 0.003s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22430,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.189335  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:32.204365  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.205088  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:32.366390  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.161s	user 0.114s	sys 0.041s 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":187,"lbm_read_time_us":10273,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29834,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:32.366995  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:32.414719  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.048s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20804,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.415259  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:32.573007  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.158s	user 0.102s	sys 0.044s 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":3642,"lbm_read_time_us":10218,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26263,"lbm_writes_lt_1ms":443,"mutex_wait_us":1669,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:32.573729  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:32.625025  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21996,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.625527  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:32.635726  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.636478  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:32.830560  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.194s	user 0.111s	sys 0.078s 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":1032,"lbm_read_time_us":11333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31951,"lbm_writes_lt_1ms":543,"mutex_wait_us":347,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:16:32.831135  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=14.095187
I20260812 06:16:32.884157  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.053s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.884676  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:32.900970  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.901566  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushMRSOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:32.939965  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushMRSOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.038s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2211,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:32.940838  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f): 448 bytes on disk
I20260812 06:16:32.941401  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: UndoDeltaBlockGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.942054  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=3.181125
I20260812 06:16:32.963547  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.021s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:32.964047  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling LogGCOp(a877832273b041689e98e6af9af2e40f): free 115943365 bytes of WAL
I20260812 06:16:32.964284  1490 log_reader.cc:385] T a877832273b041689e98e6af9af2e40f: removed 11 log segments from log reader
I20260812 06:16:32.964349  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000027 (ops 127-131)
I20260812 06:16:32.964403  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000028 (ops 132-136)
I20260812 06:16:32.964475  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000029 (ops 137-141)
I20260812 06:16:32.964533  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000030 (ops 142-146)
I20260812 06:16:32.964568  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000031 (ops 147-151)
I20260812 06:16:32.964607  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000032 (ops 152-156)
I20260812 06:16:32.964645  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000033 (ops 157-161)
I20260812 06:16:32.964682  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000034 (ops 162-166)
I20260812 06:16:32.964721  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000035 (ops 167-171)
I20260812 06:16:32.964761  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000036 (ops 172-176)
I20260812 06:16:32.964826  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000037 (ops 177-181)
I20260812 06:16:32.992079  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: LogGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:16:32.992635  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:33.013646  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.021s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.014086  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling LogGCOp(a877832273b041689e98e6af9af2e40f): free 12018006 bytes of WAL
I20260812 06:16:33.014288  1490 log_reader.cc:385] T a877832273b041689e98e6af9af2e40f: removed 1 log segments from log reader
I20260812 06:16:33.014349  1490 log.cc:1079] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: Deleting log segment in path: /tmp/dist-test-taskia5FVo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382843482-964-0/minicluster-data/ts-0-root/wals/a877832273b041689e98e6af9af2e40f/wal-000000038 (ops 182-186)
I20260812 06:16:33.016705  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: LogGCOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:33.017064  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:33.027092  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3609,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.027623  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:33.271555  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.243s	user 0.159s	sys 0.084s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123265,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":379,"lbm_read_time_us":19687,"lbm_reads_lt_1ms":875,"lbm_write_time_us":43063,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":12672,"thread_start_us":92,"threads_started":1,"update_count":4000}
I20260812 06:16:33.272287  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=18.063937
I20260812 06:16:33.330729  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.058s	user 0.041s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26091,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:33.331370  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:33.361397  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.030s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.361927  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f): perf score=2.188937
I20260812 06:16:33.362679   964 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.858s	user 1.815s	sys 0.158s
I20260812 06:16:33.377166  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: FlushDeltaMemStoresOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.015s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:16:33.377868  1609 maintenance_manager.cc:419] P ea58db517f9a4841a0955c93ac24ea5e: Scheduling MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f): perf score=1.000000
I20260812 06:16:33.444319   964 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:16:33.444906   964 tablet_server.cc:179] TabletServer@127.0.241.1:0 shutting down...
I20260812 06:16:33.549163  1490 maintenance_manager.cc:643] P ea58db517f9a4841a0955c93ac24ea5e: MajorDeltaCompactionOp(a877832273b041689e98e6af9af2e40f) complete. Timing: real 0.171s	user 0.144s	sys 0.026s Metrics: {"cfile_cache_hit":299,"cfile_cache_hit_bytes":12188379,"cfile_cache_miss":434,"cfile_cache_miss_bytes":20832249,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1508,"lbm_read_time_us":11504,"lbm_reads_lt_1ms":466,"lbm_write_time_us":36101,"lbm_writes_lt_1ms":743,"mutex_wait_us":398,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":125952,"update_count":3500}
I20260812 06:16:33.549877   964 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:33.550143   964 tablet_replica.cc:333] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e: stopping tablet replica
I20260812 06:16:33.550304   964 raft_consensus.cc:2243] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.550494   964 raft_consensus.cc:2272] T a877832273b041689e98e6af9af2e40f P ea58db517f9a4841a0955c93ac24ea5e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.565827   964 tablet_server.cc:196] TabletServer@127.0.241.1:0 shutdown complete.
I20260812 06:16:33.608920   964 master.cc:562] Master@127.0.241.62:43033 shutting down...
I20260812 06:16:33.612598   964 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.612757   964 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.612874   964 tablet_replica.cc:333] T 00000000000000000000000000000000 P 36e3597417064fa88ba6873affe67c4a: stopping tablet replica
I20260812 06:16:33.625306   964 master.cc:584] Master@127.0.241.62:43033 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5402 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10865 ms total)

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