[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:21.800361 15929 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.142.126:45645
I20260812 06:20:21.801326 15929 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:21.801889 15929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.808007 15939 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:21.808234 15929 server_base.cc:1061] running on GCE node
W20260812 06:20:21.809898 15938 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.810128 15941 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:21.810566 15929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.810686 15929 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:21.810730 15929 hybrid_clock.cc:648] HybridClock initialized: now 1786515621810727 us; error 0 us; skew 500 ppm
I20260812 06:20:21.812526 15929 webserver.cc:533] Webserver started at http://127.15.142.126:40063/ using document root <none> and password file <none>
I20260812 06:20:21.813056 15929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.813122 15929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.813381 15929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.815068 15929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/master-0-root/instance:
uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-xt4k"
I20260812 06:20:21.818427 15929 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:21.820452 15956 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.821534 15929 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:21.821652 15929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/master-0-root
uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-xt4k"
I20260812 06:20:21.821846 15929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:21.841166 15929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.841809 15929 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:21.841964 15929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.849098 15929 rpc_server.cc:307] RPC server started. Bound to: 127.15.142.126:45645
I20260812 06:20:21.849107 16056 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.142.126:45645 every 8 connection(s)
I20260812 06:20:21.851276 16057 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:21.856702 16057 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: Bootstrap starting.
I20260812 06:20:21.859179 16057 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.860105 16057 log.cc:826] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:21.861791 16057 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: No bootstrap required, opened a new log
I20260812 06:20:21.864571 16057 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER }
I20260812 06:20:21.864737 16057 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.864781 16057 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8cad5fd3e3ce44a58dddec6d4e56aa2d, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.865341 16057 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [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: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER }
I20260812 06:20:21.865481 16057 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.865554 16057 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.865672 16057 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.866415 16057 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER }
I20260812 06:20:21.866828 16057 leader_election.cc:304] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [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: 8cad5fd3e3ce44a58dddec6d4e56aa2d; no voters: 
I20260812 06:20:21.867131 16057 leader_election.cc:290] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.867223 16063 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.867458 16063 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 1 LEADER]: Becoming Leader. State: Replica: 8cad5fd3e3ce44a58dddec6d4e56aa2d, State: Running, Role: LEADER
I20260812 06:20:21.867872 16063 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [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: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER }
I20260812 06:20:21.868093 16057 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:21.869692 16067 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8cad5fd3e3ce44a58dddec6d4e56aa2d. Latest consensus state: current_term: 1 leader_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER } }
I20260812 06:20:21.869690 16066 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8cad5fd3e3ce44a58dddec6d4e56aa2d" member_type: VOTER } }
I20260812 06:20:21.869859 16067 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.869860 16066 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.870213 16089 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:21.870311 15929 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:21.872888 16089 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:21.877457 16089 catalog_manager.cc:1383] Generated new cluster ID: 7284337927714d8a8acbc12d1c38c1a9
I20260812 06:20:21.877533 16089 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:21.902267 16089 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:21.903151 16089 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:21.913792 16089 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: Generated new TSK 0
I20260812 06:20:21.914428 16089 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.935055 15929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.937668 16098 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.937779 16103 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:21.937871 15929 server_base.cc:1061] running on GCE node
W20260812 06:20:21.937692 16106 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:21.938181 15929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.938239 15929 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:21.938261 15929 hybrid_clock.cc:648] HybridClock initialized: now 1786515621938261 us; error 0 us; skew 500 ppm
I20260812 06:20:21.939163 15929 webserver.cc:533] Webserver started at http://127.15.142.65:38173/ using document root <none> and password file <none>
I20260812 06:20:21.939327 15929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.939386 15929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.939462 15929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.939888 15929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/instance:
uuid: "3db85a4bdd18411c93fba3817c400e16"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-xt4k"
I20260812 06:20:21.941686 15929 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:21.942833 16115 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.943085 15929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:21.943166 15929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root
uuid: "3db85a4bdd18411c93fba3817c400e16"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-xt4k"
I20260812 06:20:21.943236 15929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:21.962663 15929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.963475 15929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.963913 15929 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.965519 15929 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.965610 15929 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.965772 15929 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.965842 15929 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.971959 15929 rpc_server.cc:307] RPC server started. Bound to: 127.15.142.65:42319
I20260812 06:20:21.972005 16242 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.142.65:42319 every 8 connection(s)
I20260812 06:20:21.982247 16243 heartbeater.cc:344] Connected to a master server at 127.15.142.126:45645
I20260812 06:20:21.982509 16243 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:21.983016 16243 heartbeater.cc:507] Master 127.15.142.126:45645 requested a full tablet report, sending...
I20260812 06:20:21.984608 15987 ts_manager.cc:194] Registered new tserver with Master: 3db85a4bdd18411c93fba3817c400e16 (127.15.142.65:42319)
I20260812 06:20:21.984999 15929 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01237231s
I20260812 06:20:21.986146 15987 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54936
I20260812 06:20:21.994249 15987 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54942:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:22.007647 16171 tablet_service.cc:1511] Processing CreateTablet for tablet af84f31682e3485a8a9e41cf85174c8b (DEFAULT_TABLE table=heavy-update-compaction-test [id=1c9f43c520ae4d75a490b0fcdd894bc7]), partition=
I20260812 06:20:22.008103 16171 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet af84f31682e3485a8a9e41cf85174c8b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.010352 16264 tablet_bootstrap.cc:492] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Bootstrap starting.
I20260812 06:20:22.011375 16264 tablet_bootstrap.cc:654] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.012928 16264 tablet_bootstrap.cc:492] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: No bootstrap required, opened a new log
I20260812 06:20:22.013013 16264 ts_tablet_manager.cc:1403] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:22.013474 16264 raft_consensus.cc:359] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3db85a4bdd18411c93fba3817c400e16" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 42319 } }
I20260812 06:20:22.013649 16264 raft_consensus.cc:385] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.013898 16264 raft_consensus.cc:740] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3db85a4bdd18411c93fba3817c400e16, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.014057 16264 consensus_queue.cc:260] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [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: "3db85a4bdd18411c93fba3817c400e16" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 42319 } }
I20260812 06:20:22.014150 16264 raft_consensus.cc:399] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.014213 16264 raft_consensus.cc:493] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.014266 16264 raft_consensus.cc:3060] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.015036 16264 raft_consensus.cc:515] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3db85a4bdd18411c93fba3817c400e16" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 42319 } }
I20260812 06:20:22.015156 16264 leader_election.cc:304] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [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: 3db85a4bdd18411c93fba3817c400e16; no voters: 
I20260812 06:20:22.015350 16264 leader_election.cc:290] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.015465 16270 raft_consensus.cc:2804] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.015681 16264 ts_tablet_manager.cc:1434] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:22.015679 16270 raft_consensus.cc:697] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 1 LEADER]: Becoming Leader. State: Replica: 3db85a4bdd18411c93fba3817c400e16, State: Running, Role: LEADER
I20260812 06:20:22.015942 16243 heartbeater.cc:499] Master 127.15.142.126:45645 was elected leader, sending a full tablet report...
I20260812 06:20:22.015925 16270 consensus_queue.cc:237] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [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: "3db85a4bdd18411c93fba3817c400e16" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 42319 } }
I20260812 06:20:22.018989 15987 catalog_manager.cc:5719] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3db85a4bdd18411c93fba3817c400e16 (127.15.142.65). New cstate: current_term: 1 leader_uuid: "3db85a4bdd18411c93fba3817c400e16" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3db85a4bdd18411c93fba3817c400e16" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 42319 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:22.075987 15929 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.014s	sys 0.009s
I20260812 06:20:22.223140 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b): perf score=19.054940
I20260812 06:20:22.400461 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.177s	user 0.141s	sys 0.036s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":211,"delete_count":0,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":772,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44034,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":112,"threads_started":1,"update_count":1500}
I20260812 06:20:22.401630 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling LogGCOp(af84f31682e3485a8a9e41cf85174c8b): free 20743880 bytes of WAL
I20260812 06:20:22.401916 16126 log_reader.cc:385] T af84f31682e3485a8a9e41cf85174c8b: removed 2 log segments from log reader
I20260812 06:20:22.402004 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000001 (ops 1-6)
I20260812 06:20:22.402076 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000002 (ops 7-11)
I20260812 06:20:22.405743 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: LogGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:22.406078 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b): 16821647 bytes on disk
I20260812 06:20:22.406596 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b) 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:20:22.407060 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:22.427000 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.020s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.427417 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:22.440696 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.441156 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:22.610170 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.169s	user 0.109s	sys 0.060s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405550,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":856,"lbm_read_time_us":11932,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27716,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":301,"threads_started":5,"update_count":2450}
I20260812 06:20:22.610749 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:22.646261 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.035s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14310,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.646734 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:22.661029 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.661610 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:22.784734 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.123s	user 0.086s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1035,"lbm_read_time_us":8634,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24031,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:20:22.785205 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:22.829440 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.044s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14074,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.829946 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:22.840015 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.840561 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:22.969521 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.129s	user 0.123s	sys 0.005s 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":277,"lbm_read_time_us":10435,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24316,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:20:22.970220 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:23.011070 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.041s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14213,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:20:23.011634 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.028273 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.028795 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:23.147382 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.118s	user 0.102s	sys 0.015s 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":605,"lbm_read_time_us":7960,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25036,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:20:23.147995 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:23.190927 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14279,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.191565 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.207033 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.207557 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:23.356159 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.148s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":778,"lbm_read_time_us":10410,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26286,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:20:23.356719 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:23.398460 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.042s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14274,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.398964 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.409705 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.410298 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:23.528460 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.118s	user 0.086s	sys 0.031s 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":657,"lbm_read_time_us":8599,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21558,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:20:23.528993 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:23.571801 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.043s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14218,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.572371 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.587339 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5436,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.587828 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:23.615422 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1913,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1425,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:23.616250 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling LogGCOp(af84f31682e3485a8a9e41cf85174c8b): free 112692357 bytes of WAL
I20260812 06:20:23.616496 16126 log_reader.cc:385] T af84f31682e3485a8a9e41cf85174c8b: removed 11 log segments from log reader
I20260812 06:20:23.616554 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000003 (ops 12-16)
I20260812 06:20:23.616619 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000004 (ops 17-21)
I20260812 06:20:23.616647 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000005 (ops 22-26)
I20260812 06:20:23.616671 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000006 (ops 27-31)
I20260812 06:20:23.616698 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000007 (ops 32-36)
I20260812 06:20:23.616729 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000008 (ops 37-41)
I20260812 06:20:23.616761 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000009 (ops 42-46)
I20260812 06:20:23.616799 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000010 (ops 47-51)
I20260812 06:20:23.616832 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000011 (ops 52-56)
I20260812 06:20:23.616858 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000012 (ops 57-61)
I20260812 06:20:23.616886 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000013 (ops 62-66)
I20260812 06:20:23.642585 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: LogGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:23.643095 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b): 448 bytes on disk
I20260812 06:20:23.643718 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b) 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:20:23.644255 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=3.181125
I20260812 06:20:23.662806 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6513,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.663268 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.673018 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3443,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.673620 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:23.844421 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.171s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":274,"lbm_read_time_us":12585,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29853,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:23.844884 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:23.891441 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.046s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409911,"delete_count":0,"lbm_write_time_us":19172,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.891876 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:23.906486 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.906893 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:24.070972 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.164s	user 0.123s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":11399,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29186,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2500}
I20260812 06:20:24.071684 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:24.126006 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.054s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.126489 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:24.136291 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.136741 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:24.313716 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.177s	user 0.125s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":542,"lbm_read_time_us":13257,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28517,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:20:24.314242 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:24.359166 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.045s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18976,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.359692 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:24.507341 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.147s	user 0.105s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1171,"lbm_read_time_us":9697,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22897,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:20:24.507875 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:24.557512 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.050s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19816,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.558102 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:24.570631 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.571354 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:24.739882 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.168s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":800,"lbm_read_time_us":12611,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25862,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.740459 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:24.786424 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.046s	user 0.032s	sys 0.005s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16724,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.786983 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:24.798050 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.804687 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:24.939689 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.135s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":9460,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25391,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:20:24.940490 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=11.118625
I20260812 06:20:24.974184 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.034s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13899,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.974695 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:24.998850 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.024s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.999404 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:25.009092 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.009719 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:25.037817 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.028s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1060,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1490,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:25.038522 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling LogGCOp(af84f31682e3485a8a9e41cf85174c8b): free 136728237 bytes of WAL
I20260812 06:20:25.038749 16126 log_reader.cc:385] T af84f31682e3485a8a9e41cf85174c8b: removed 13 log segments from log reader
I20260812 06:20:25.038806 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000014 (ops 67-71)
I20260812 06:20:25.038852 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000015 (ops 72-76)
I20260812 06:20:25.038883 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000016 (ops 77-81)
I20260812 06:20:25.038904 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000017 (ops 82-86)
I20260812 06:20:25.038936 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000018 (ops 87-91)
I20260812 06:20:25.038968 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000019 (ops 92-97)
I20260812 06:20:25.038992 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000020 (ops 98-102)
I20260812 06:20:25.039018 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000021 (ops 103-106)
I20260812 06:20:25.039044 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000022 (ops 107-111)
I20260812 06:20:25.039069 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000023 (ops 112-116)
I20260812 06:20:25.039098 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000024 (ops 117-121)
I20260812 06:20:25.039129 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000025 (ops 122-126)
I20260812 06:20:25.039152 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000026 (ops 127-131)
I20260812 06:20:25.068113 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: LogGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:25.068575 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b): 481 bytes on disk
I20260812 06:20:25.069039 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.069777 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=3.181125
I20260812 06:20:25.092289 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.022s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4841095,"delete_count":0,"lbm_write_time_us":4982,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:20:25.092783 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:25.105249 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:25.105767 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:25.316663 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.211s	user 0.134s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020838,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":271,"lbm_read_time_us":15380,"lbm_reads_lt_1ms":775,"lbm_write_time_us":35886,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:20:25.317142 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:25.376291 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.059s	user 0.018s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26010,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.376866 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:25.395150 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.018s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.395678 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:25.552178 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.156s	user 0.081s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":431,"lbm_read_time_us":11941,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24512,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:25.552676 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:25.610662 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.058s	user 0.016s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19208,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.611177 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:25.621431 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.621845 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:25.777518 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.156s	user 0.101s	sys 0.054s 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":223,"lbm_read_time_us":11665,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26962,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:25.777979 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=11.118625
I20260812 06:20:25.809118 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.031s	user 0.027s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13191,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.809603 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:25.820179 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3768,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.820930 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:25.958297 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.137s	user 0.097s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":512,"lbm_read_time_us":10391,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19494,"lbm_writes_lt_1ms":443,"mutex_wait_us":331,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:25.958827 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:25.989861 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.031s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12988,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.990332 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:26.005312 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.005893 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:26.129753 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.124s	user 0.093s	sys 0.029s 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":294,"lbm_read_time_us":8181,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23643,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:20:26.130414 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:26.164944 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.034s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.165488 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:26.180514 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.181047 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:26.296657 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.115s	user 0.099s	sys 0.016s 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":242,"lbm_read_time_us":8247,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22458,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:26.297139 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=10.126437
I20260812 06:20:26.341156 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.044s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13537,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.341657 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:26.351933 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.352313 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:26.379935 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushMRSOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.027s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1197,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1247,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:26.380595 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling LogGCOp(af84f31682e3485a8a9e41cf85174c8b): free 112239510 bytes of WAL
I20260812 06:20:26.380784 16126 log_reader.cc:385] T af84f31682e3485a8a9e41cf85174c8b: removed 11 log segments from log reader
I20260812 06:20:26.380826 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000027 (ops 132-136)
I20260812 06:20:26.380864 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000028 (ops 137-141)
I20260812 06:20:26.380897 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000029 (ops 142-146)
I20260812 06:20:26.380944 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000030 (ops 147-150)
I20260812 06:20:26.381009 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000031 (ops 151-155)
I20260812 06:20:26.381047 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000032 (ops 156-160)
I20260812 06:20:26.381102 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000033 (ops 161-165)
I20260812 06:20:26.381137 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000034 (ops 166-170)
I20260812 06:20:26.381162 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000035 (ops 171-175)
I20260812 06:20:26.381217 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000036 (ops 176-180)
I20260812 06:20:26.381251 16126 log.cc:1079] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/af84f31682e3485a8a9e41cf85174c8b/wal-000000037 (ops 181-185)
I20260812 06:20:26.405531 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: LogGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:26.405926 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b): 446 bytes on disk
I20260812 06:20:26.406291 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: UndoDeltaBlockGCOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.406778 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:26.416848 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.417199 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:26.591178 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.174s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":825,"lbm_read_time_us":12663,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28061,"lbm_writes_lt_1ms":543,"mutex_wait_us":245,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"thread_start_us":75,"threads_started":1,"update_count":2500}
I20260812 06:20:26.591719 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=14.095187
I20260812 06:20:26.647012 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.055s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.647662 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=2.188937
I20260812 06:20:26.658733 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.659214 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b): perf score=1.000000
I20260812 06:20:26.744802 15929 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.669s	user 1.697s	sys 0.170s
I20260812 06:20:26.810410 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: MajorDeltaCompactionOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.151s	user 0.082s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":11587,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25119,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":50816,"update_count":2500}
I20260812 06:20:26.812706 16245 maintenance_manager.cc:419] P 3db85a4bdd18411c93fba3817c400e16: Scheduling FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b): perf score=6.157687
I20260812 06:20:26.817239 15929 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:20:26.817762 15929 tablet_server.cc:179] TabletServer@127.15.142.65:0 shutting down...
I20260812 06:20:26.832906 16126 maintenance_manager.cc:643] P 3db85a4bdd18411c93fba3817c400e16: FlushDeltaMemStoresOp(af84f31682e3485a8a9e41cf85174c8b) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8160,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:26.833493 15929 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.833850 15929 tablet_replica.cc:333] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16: stopping tablet replica
I20260812 06:20:26.834055 15929 raft_consensus.cc:2243] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.834260 15929 raft_consensus.cc:2272] T af84f31682e3485a8a9e41cf85174c8b P 3db85a4bdd18411c93fba3817c400e16 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.838205 15929 tablet_server.cc:196] TabletServer@127.15.142.65:0 shutdown complete.
I20260812 06:20:26.854982 15929 master.cc:562] Master@127.15.142.126:45645 shutting down...
I20260812 06:20:26.858273 15929 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.858412 15929 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.858484 15929 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8cad5fd3e3ce44a58dddec6d4e56aa2d: stopping tablet replica
I20260812 06:20:26.870396 15929 master.cc:584] Master@127.15.142.126:45645 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5145 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:26.955482 15929 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.142.126:40269
I20260812 06:20:26.955852 15929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.957886 16307 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.958007 16313 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.957967 16308 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.958094 15929 server_base.cc:1061] running on GCE node
I20260812 06:20:26.958303 15929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.958355 15929 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.958370 15929 hybrid_clock.cc:648] HybridClock initialized: now 1786515626958370 us; error 0 us; skew 500 ppm
I20260812 06:20:26.959133 15929 webserver.cc:533] Webserver started at http://127.15.142.126:34109/ using document root <none> and password file <none>
I20260812 06:20:26.959281 15929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.959332 15929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.959407 15929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.959779 15929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/master-0-root/instance:
uuid: "9c7a095f0f4f484a8ce41380fd414dd3"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-xt4k"
I20260812 06:20:26.961248 15929 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.962174 16321 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.962406 15929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.962473 15929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/master-0-root
uuid: "9c7a095f0f4f484a8ce41380fd414dd3"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-xt4k"
I20260812 06:20:26.962543 15929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.971040 15929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.971331 15929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.975169 15929 rpc_server.cc:307] RPC server started. Bound to: 127.15.142.126:40269
I20260812 06:20:26.979573 16424 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.142.126:40269 every 8 connection(s)
I20260812 06:20:26.980008 16425 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.981727 16425 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3: Bootstrap starting.
I20260812 06:20:26.982486 16425 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.983398 16425 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3: No bootstrap required, opened a new log
I20260812 06:20:26.983764 16425 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER }
I20260812 06:20:26.983847 16425 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.983868 16425 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9c7a095f0f4f484a8ce41380fd414dd3, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.984004 16425 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [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: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER }
I20260812 06:20:26.984076 16425 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.984097 16425 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.984139 16425 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.984789 16425 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER }
I20260812 06:20:26.984911 16425 leader_election.cc:304] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [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: 9c7a095f0f4f484a8ce41380fd414dd3; no voters: 
I20260812 06:20:26.985097 16425 leader_election.cc:290] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.985205 16429 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.985395 16429 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 1 LEADER]: Becoming Leader. State: Replica: 9c7a095f0f4f484a8ce41380fd414dd3, State: Running, Role: LEADER
I20260812 06:20:26.985499 16425 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.985529 16429 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [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: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER }
I20260812 06:20:26.985947 16432 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9c7a095f0f4f484a8ce41380fd414dd3. Latest consensus state: current_term: 1 leader_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER } }
I20260812 06:20:26.985924 16430 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c7a095f0f4f484a8ce41380fd414dd3" member_type: VOTER } }
I20260812 06:20:26.986053 16432 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.986070 16430 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.986336 16437 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.987119 16437 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.987286 15929 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.988860 16437 catalog_manager.cc:1383] Generated new cluster ID: aea0d327a3c04fea93c25ff03e344be8
I20260812 06:20:26.988921 16437 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:27.010687 16437 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:27.011298 16437 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:27.016649 16437 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3: Generated new TSK 0
I20260812 06:20:27.016801 16437 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:27.019577 15929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:27.021376 16474 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.021521 15929 server_base.cc:1061] running on GCE node
W20260812 06:20:27.021545 16480 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.021565 16475 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.022037 15929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:27.022119 15929 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:27.022148 15929 hybrid_clock.cc:648] HybridClock initialized: now 1786515627022148 us; error 0 us; skew 500 ppm
I20260812 06:20:27.023384 15929 webserver.cc:533] Webserver started at http://127.15.142.65:37967/ using document root <none> and password file <none>
I20260812 06:20:27.023612 15929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:27.023672 15929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:27.023885 15929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:27.024251 15929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/instance:
uuid: "edc7932a4263439c8f9d41aff3f9229a"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-xt4k"
I20260812 06:20:27.025735 15929 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:27.026816 16489 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.027104 15929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:27.027172 15929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root
uuid: "edc7932a4263439c8f9d41aff3f9229a"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-xt4k"
I20260812 06:20:27.027228 15929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:27.035913 15929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:27.036273 15929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:27.036592 15929 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:27.037041 15929 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:27.037079 15929 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.037114 15929 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:27.037142 15929 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.041105 15929 rpc_server.cc:307] RPC server started. Bound to: 127.15.142.65:44123
I20260812 06:20:27.041203 16615 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.142.65:44123 every 8 connection(s)
I20260812 06:20:27.048866 16618 heartbeater.cc:344] Connected to a master server at 127.15.142.126:40269
I20260812 06:20:27.048974 16618 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:27.049207 16618 heartbeater.cc:507] Master 127.15.142.126:40269 requested a full tablet report, sending...
I20260812 06:20:27.049826 16356 ts_manager.cc:194] Registered new tserver with Master: edc7932a4263439c8f9d41aff3f9229a (127.15.142.65:44123)
I20260812 06:20:27.050383 15929 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008884708s
I20260812 06:20:27.050522 16356 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47390
I20260812 06:20:27.056963 16356 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47402:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:27.064926 16545 tablet_service.cc:1511] Processing CreateTablet for tablet aad0793688b5407e8a5db20397f16f23 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9dbf053dd2f94a9dbb5d6bc424f0de73]), partition=
I20260812 06:20:27.065173 16545 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aad0793688b5407e8a5db20397f16f23. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:27.066992 16641 tablet_bootstrap.cc:492] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Bootstrap starting.
I20260812 06:20:27.067855 16641 tablet_bootstrap.cc:654] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:27.068848 16641 tablet_bootstrap.cc:492] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: No bootstrap required, opened a new log
I20260812 06:20:27.068929 16641 ts_tablet_manager.cc:1403] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:27.069339 16641 raft_consensus.cc:359] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edc7932a4263439c8f9d41aff3f9229a" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 44123 } }
I20260812 06:20:27.069429 16641 raft_consensus.cc:385] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:27.069463 16641 raft_consensus.cc:740] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: edc7932a4263439c8f9d41aff3f9229a, State: Initialized, Role: FOLLOWER
I20260812 06:20:27.069598 16641 consensus_queue.cc:260] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [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: "edc7932a4263439c8f9d41aff3f9229a" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 44123 } }
I20260812 06:20:27.069669 16641 raft_consensus.cc:399] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:27.069703 16641 raft_consensus.cc:493] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:27.069752 16641 raft_consensus.cc:3060] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:27.070520 16641 raft_consensus.cc:515] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edc7932a4263439c8f9d41aff3f9229a" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 44123 } }
I20260812 06:20:27.070662 16641 leader_election.cc:304] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [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: edc7932a4263439c8f9d41aff3f9229a; no voters: 
I20260812 06:20:27.070834 16641 leader_election.cc:290] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:27.070925 16643 raft_consensus.cc:2804] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:27.071126 16643 raft_consensus.cc:697] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 1 LEADER]: Becoming Leader. State: Replica: edc7932a4263439c8f9d41aff3f9229a, State: Running, Role: LEADER
I20260812 06:20:27.071146 16641 ts_tablet_manager.cc:1434] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:27.071153 16618 heartbeater.cc:499] Master 127.15.142.126:40269 was elected leader, sending a full tablet report...
I20260812 06:20:27.071323 16643 consensus_queue.cc:237] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [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: "edc7932a4263439c8f9d41aff3f9229a" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 44123 } }
I20260812 06:20:27.072546 16356 catalog_manager.cc:5719] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a reported cstate change: term changed from 0 to 1, leader changed from <none> to edc7932a4263439c8f9d41aff3f9229a (127.15.142.65). New cstate: current_term: 1 leader_uuid: "edc7932a4263439c8f9d41aff3f9229a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "edc7932a4263439c8f9d41aff3f9229a" member_type: VOTER last_known_addr { host: "127.15.142.65" port: 44123 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:27.126432 15929 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.015s	sys 0.008s
I20260812 06:20:27.292164 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushMRSOp(aad0793688b5407e8a5db20397f16f23): perf score=23.023690
I20260812 06:20:27.454519 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushMRSOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.162s	user 0.119s	sys 0.040s Metrics: {"bytes_written":13579241,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":832,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40918,"lbm_writes_lt_1ms":888,"mutex_wait_us":770,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":7936,"update_count":1655}
I20260812 06:20:27.455139 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling LogGCOp(aad0793688b5407e8a5db20397f16f23): free 20743880 bytes of WAL
I20260812 06:20:27.455359 16502 log_reader.cc:385] T aad0793688b5407e8a5db20397f16f23: removed 2 log segments from log reader
I20260812 06:20:27.455420 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000001 (ops 1-6)
I20260812 06:20:27.455470 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000002 (ops 7-11)
I20260812 06:20:27.460167 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: LogGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:27.460639 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23): 20513813 bytes on disk
I20260812 06:20:27.461122 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.461530 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=3.181125
I20260812 06:20:27.475946 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4759047,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:20:27.476323 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=1.196750
I20260812 06:20:27.482388 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":1910,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:20:27.482729 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:27.651500 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.169s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815762,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":499,"lbm_read_time_us":10616,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25903,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":300,"threads_started":5,"update_count":2500}
I20260812 06:20:27.652027 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:27.693642 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.041s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.694235 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:27.850239 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.156s	user 0.095s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":171,"lbm_read_time_us":9362,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23487,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39936,"update_count":2000}
I20260812 06:20:27.850701 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:27.906638 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.056s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409908,"delete_count":0,"lbm_write_time_us":21937,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.907064 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:27.916877 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.917426 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:28.097326 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.180s	user 0.107s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":11055,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26846,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:20:28.097837 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:28.149554 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.052s	user 0.014s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23099,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.150068 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.163992 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.164538 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:28.317973 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.153s	user 0.109s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":988,"lbm_read_time_us":9009,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26288,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:20:28.318519 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:28.360533 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.042s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17625,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.361020 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.371272 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.371789 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:28.516525 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.145s	user 0.117s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":9713,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28456,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:20:28.517040 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=11.118625
I20260812 06:20:28.553649 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":12922847,"delete_count":0,"lbm_write_time_us":15368,"lbm_writes_lt_1ms":318,"reinsert_count":0,"update_count":1575}
I20260812 06:20:28.554142 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.575670 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.021s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5510,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:20:28.576159 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.585274 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3342,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.585685 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushMRSOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:28.614110 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushMRSOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.028s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1151,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1269,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:28.614753 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling LogGCOp(aad0793688b5407e8a5db20397f16f23): free 120100327 bytes of WAL
I20260812 06:20:28.614992 16502 log_reader.cc:385] T aad0793688b5407e8a5db20397f16f23: removed 12 log segments from log reader
I20260812 06:20:28.615047 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000003 (ops 12-16)
I20260812 06:20:28.615084 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000004 (ops 17-21)
I20260812 06:20:28.615149 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000005 (ops 22-26)
I20260812 06:20:28.615185 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000006 (ops 27-31)
I20260812 06:20:28.615209 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000007 (ops 32-36)
I20260812 06:20:28.615239 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000008 (ops 37-40)
I20260812 06:20:28.615270 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000009 (ops 41-45)
I20260812 06:20:28.615298 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000010 (ops 46-50)
I20260812 06:20:28.615329 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000011 (ops 51-54)
I20260812 06:20:28.615357 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000012 (ops 55-59)
I20260812 06:20:28.615386 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000013 (ops 60-64)
I20260812 06:20:28.615417 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000014 (ops 65-68)
I20260812 06:20:28.637349 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: LogGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:28.637728 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=3.181125
I20260812 06:20:28.657088 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.019s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6517,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.657495 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23): 462 bytes on disk
I20260812 06:20:28.657847 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23) 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:20:28.658265 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.675887 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.017s	user 0.004s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.676506 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:28.903551 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.227s	user 0.138s	sys 0.077s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020829,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":227,"lbm_read_time_us":14456,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36871,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:20:28.904160 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=18.063937
I20260812 06:20:28.966568 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.062s	user 0.038s	sys 0.019s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":25530,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.967195 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:28.983204 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.983768 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:29.176739 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.193s	user 0.149s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":15834,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28917,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":3000}
I20260812 06:20:29.177286 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:29.232649 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.055s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18865,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.233125 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:29.248623 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.249572 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:29.427086 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.177s	user 0.108s	sys 0.062s 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":557,"lbm_read_time_us":12533,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28711,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:20:29.427551 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:29.482316 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.055s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.482775 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:29.492838 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.493202 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:29.652221 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.159s	user 0.116s	sys 0.041s 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":336,"lbm_read_time_us":11367,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24413,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:29.652794 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=11.118625
I20260812 06:20:29.688803 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.036s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15125,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:29.689653 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:29.717864 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.028s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4508,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.720448 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:29.735715 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.736223 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:29.916479 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.180s	user 0.114s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":595,"lbm_read_time_us":12096,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28897,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:20:29.917595 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:29.960297 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.043s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17730,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.960810 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:29.985265 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.024s	user 0.008s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.985736 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushMRSOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:30.022902 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushMRSOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.037s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1052,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1392,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.023676 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling LogGCOp(aad0793688b5407e8a5db20397f16f23): free 120553388 bytes of WAL
I20260812 06:20:30.023931 16502 log_reader.cc:385] T aad0793688b5407e8a5db20397f16f23: removed 12 log segments from log reader
I20260812 06:20:30.023988 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000015 (ops 69-73)
I20260812 06:20:30.024029 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000016 (ops 74-78)
I20260812 06:20:30.024063 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000017 (ops 79-83)
I20260812 06:20:30.024089 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000018 (ops 84-88)
I20260812 06:20:30.024121 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000019 (ops 89-92)
I20260812 06:20:30.024152 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000020 (ops 93-97)
I20260812 06:20:30.024183 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000021 (ops 98-102)
I20260812 06:20:30.024214 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000022 (ops 103-107)
I20260812 06:20:30.024243 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000023 (ops 108-112)
I20260812 06:20:30.024273 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000024 (ops 113-116)
I20260812 06:20:30.024302 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000025 (ops 117-121)
I20260812 06:20:30.024329 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000026 (ops 122-126)
I20260812 06:20:30.045410 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: LogGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:30.045814 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23): 448 bytes on disk
I20260812 06:20:30.046279 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.046818 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=3.181125
I20260812 06:20:30.069514 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.023s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4845,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.069943 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:30.079041 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3275,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.079588 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:30.309659 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.230s	user 0.160s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":217,"lbm_read_time_us":14398,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35522,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23296,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:30.310266 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=18.063937
I20260812 06:20:30.361820 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.051s	user 0.036s	sys 0.012s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":21661,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.362367 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:30.520612 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.157s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815565,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":598,"lbm_read_time_us":10746,"lbm_reads_lt_1ms":563,"lbm_write_time_us":26503,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:30.521073 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:30.571868 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.051s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17348,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.572465 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:30.587208 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.587728 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:30.757915 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.170s	user 0.091s	sys 0.070s 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":851,"lbm_read_time_us":11644,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26491,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:20:30.758442 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:30.812584 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.054s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16036,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.813122 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:30.823210 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.823618 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:30.993008 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.169s	user 0.116s	sys 0.047s 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":141,"lbm_read_time_us":12372,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25824,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:20:30.993649 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=11.118625
I20260812 06:20:31.031981 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.038s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15376,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.032606 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.052155 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.019s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.052639 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.065734 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4797,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.066232 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:31.241312 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.175s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":142,"lbm_read_time_us":9823,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27090,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:31.241832 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=14.095187
I20260812 06:20:31.292295 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.050s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22538,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.292874 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.311683 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.312259 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushMRSOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:31.348717 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushMRSOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.036s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1269,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1393,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:31.349812 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23): 446 bytes on disk
I20260812 06:20:31.350327 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: UndoDeltaBlockGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.351028 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=3.181125
I20260812 06:20:31.372509 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.021s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7129,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:31.372962 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling LogGCOp(aad0793688b5407e8a5db20397f16f23): free 112692548 bytes of WAL
I20260812 06:20:31.373153 16502 log_reader.cc:385] T aad0793688b5407e8a5db20397f16f23: removed 11 log segments from log reader
I20260812 06:20:31.373195 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000027 (ops 127-131)
I20260812 06:20:31.373224 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000028 (ops 132-136)
I20260812 06:20:31.373253 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000029 (ops 137-141)
I20260812 06:20:31.373283 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000030 (ops 142-146)
I20260812 06:20:31.373315 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000031 (ops 147-151)
I20260812 06:20:31.373345 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000032 (ops 152-156)
I20260812 06:20:31.373377 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000033 (ops 157-161)
I20260812 06:20:31.373418 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000034 (ops 162-166)
I20260812 06:20:31.373442 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000035 (ops 167-171)
I20260812 06:20:31.373474 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000036 (ops 172-176)
I20260812 06:20:31.373505 16502 log.cc:1079] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: Deleting log segment in path: /tmp/dist-test-taskVkAjKs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515621789684-15929-0/minicluster-data/ts-0-root/wals/aad0793688b5407e8a5db20397f16f23/wal-000000037 (ops 177-181)
I20260812 06:20:31.392192 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: LogGCOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.019s	user 0.000s	sys 0.015s Metrics: {}
I20260812 06:20:31.392644 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.415640 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.023s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.416172 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.425889 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.426290 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:31.648770 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.222s	user 0.148s	sys 0.072s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123261,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":318,"lbm_read_time_us":16635,"lbm_reads_lt_1ms":875,"lbm_write_time_us":35559,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":75,"threads_started":1,"update_count":4000}
I20260812 06:20:31.650313 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=18.063937
I20260812 06:20:31.699513 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":21125,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:31.699928 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.722237 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.022s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.722693 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23): perf score=2.188937
I20260812 06:20:31.733505 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: FlushDeltaMemStoresOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.733866 16620 maintenance_manager.cc:419] P edc7932a4263439c8f9d41aff3f9229a: Scheduling MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23): perf score=1.000000
I20260812 06:20:31.765126 15929 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.639s	user 1.653s	sys 0.185s
I20260812 06:20:31.832170 15929 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.001s	sys 0.000s
I20260812 06:20:31.832660 15929 tablet_server.cc:179] TabletServer@127.15.142.65:0 shutting down...
I20260812 06:20:31.889158 16502 maintenance_manager.cc:643] P edc7932a4263439c8f9d41aff3f9229a: MajorDeltaCompactionOp(aad0793688b5407e8a5db20397f16f23) complete. Timing: real 0.155s	user 0.135s	sys 0.019s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020630,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":739,"lbm_read_time_us":12935,"lbm_reads_lt_1ms":769,"lbm_write_time_us":29814,"lbm_writes_lt_1ms":743,"mutex_wait_us":306,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":3500}
I20260812 06:20:31.889770 15929 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.890002 15929 tablet_replica.cc:333] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a: stopping tablet replica
I20260812 06:20:31.890115 15929 raft_consensus.cc:2243] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.890260 15929 raft_consensus.cc:2272] T aad0793688b5407e8a5db20397f16f23 P edc7932a4263439c8f9d41aff3f9229a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.895618 15929 tablet_server.cc:196] TabletServer@127.15.142.65:0 shutdown complete.
I20260812 06:20:31.947120 15929 master.cc:562] Master@127.15.142.126:40269 shutting down...
I20260812 06:20:31.950143 15929 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.950309 15929 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.950376 15929 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9c7a095f0f4f484a8ce41380fd414dd3: stopping tablet replica
I20260812 06:20:31.962617 15929 master.cc:584] Master@127.15.142.126:40269 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5091 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10237 ms total)

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