[==========] 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:19:45.430835  6260 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.29.62:37537
I20260812 06:19:45.431861  6260 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:19:45.432498  6260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:45.438838  6270 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:19:45.439023  6271 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:19:45.439040  6260 server_base.cc:1061] running on GCE node
W20260812 06:19:45.439270  6275 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:19:45.439723  6260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:45.439844  6260 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:19:45.439970  6260 hybrid_clock.cc:648] HybridClock initialized: now 1786515585439965 us; error 0 us; skew 500 ppm
I20260812 06:19:45.442207  6260 webserver.cc:533] Webserver started at http://127.6.29.62:40243/ using document root <none> and password file <none>
I20260812 06:19:45.442879  6260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:45.442981  6260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:45.443245  6260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:45.445180  6260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/master-0-root/instance:
uuid: "4c037112b30b400e981f714626f34603"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-44d2"
I20260812 06:19:45.448958  6260 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:19:45.451227  6285 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:19:45.452399  6260 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:45.452546  6260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/master-0-root
uuid: "4c037112b30b400e981f714626f34603"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-44d2"
I20260812 06:19:45.452680  6260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-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:19:45.461968  6260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:45.462608  6260 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:19:45.462795  6260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:45.471030  6260 rpc_server.cc:307] RPC server started. Bound to: 127.6.29.62:37537
I20260812 06:19:45.471057  6370 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.29.62:37537 every 8 connection(s)
I20260812 06:19:45.473438  6372 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:19:45.478940  6372 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: Bootstrap starting.
I20260812 06:19:45.481402  6372 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:45.482360  6372 log.cc:826] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:45.484086  6372 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: No bootstrap required, opened a new log
I20260812 06:19:45.486814  6372 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c037112b30b400e981f714626f34603" member_type: VOTER }
I20260812 06:19:45.486976  6372 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:45.487054  6372 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c037112b30b400e981f714626f34603, State: Initialized, Role: FOLLOWER
I20260812 06:19:45.487650  6372 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [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: "4c037112b30b400e981f714626f34603" member_type: VOTER }
I20260812 06:19:45.487782  6372 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:45.487880  6372 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:45.488019  6372 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:45.488868  6372 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c037112b30b400e981f714626f34603" member_type: VOTER }
I20260812 06:19:45.489338  6372 leader_election.cc:304] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [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: 4c037112b30b400e981f714626f34603; no voters: 
I20260812 06:19:45.489667  6372 leader_election.cc:290] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:45.489856  6376 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:45.490160  6376 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 1 LEADER]: Becoming Leader. State: Replica: 4c037112b30b400e981f714626f34603, State: Running, Role: LEADER
I20260812 06:19:45.490588  6376 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [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: "4c037112b30b400e981f714626f34603" member_type: VOTER }
I20260812 06:19:45.490752  6372 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:45.492413  6383 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4c037112b30b400e981f714626f34603. Latest consensus state: current_term: 1 leader_uuid: "4c037112b30b400e981f714626f34603" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c037112b30b400e981f714626f34603" member_type: VOTER } }
I20260812 06:19:45.492466  6378 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4c037112b30b400e981f714626f34603" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c037112b30b400e981f714626f34603" member_type: VOTER } }
I20260812 06:19:45.492565  6383 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.492588  6378 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.493034  6402 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:45.493324  6260 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:45.495623  6402 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:45.500311  6402 catalog_manager.cc:1383] Generated new cluster ID: 53d5796835054955b343491fc1d32c9a
I20260812 06:19:45.500398  6402 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:45.510414  6402 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:45.511623  6402 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:45.528863  6402 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: Generated new TSK 0
I20260812 06:19:45.529712  6402 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:45.558303  6260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:45.561332  6422 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:19:45.561342  6420 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:45.561412  6419 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:19:45.561702  6260 server_base.cc:1061] running on GCE node
I20260812 06:19:45.561956  6260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:45.562016  6260 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:19:45.562041  6260 hybrid_clock.cc:648] HybridClock initialized: now 1786515585562041 us; error 0 us; skew 500 ppm
I20260812 06:19:45.563047  6260 webserver.cc:533] Webserver started at http://127.6.29.1:36529/ using document root <none> and password file <none>
I20260812 06:19:45.563225  6260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:45.563288  6260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:45.563369  6260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:45.563832  6260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/instance:
uuid: "bfea105265784f0facf3355b08bbcf5c"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-44d2"
I20260812 06:19:45.565832  6260 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:45.567018  6429 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:19:45.567334  6260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:45.567415  6260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root
uuid: "bfea105265784f0facf3355b08bbcf5c"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-44d2"
I20260812 06:19:45.567492  6260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-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:19:45.580606  6260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:45.581169  6260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:45.581676  6260 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:45.582661  6260 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:45.582737  6260 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:45.582832  6260 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:45.582875  6260 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:45.589847  6260 rpc_server.cc:307] RPC server started. Bound to: 127.6.29.1:44367
I20260812 06:19:45.589875  6523 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.29.1:44367 every 8 connection(s)
I20260812 06:19:45.600212  6524 heartbeater.cc:344] Connected to a master server at 127.6.29.62:37537
I20260812 06:19:45.600560  6524 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:45.601034  6524 heartbeater.cc:507] Master 127.6.29.62:37537 requested a full tablet report, sending...
I20260812 06:19:45.602598  6311 ts_manager.cc:194] Registered new tserver with Master: bfea105265784f0facf3355b08bbcf5c (127.6.29.1:44367)
I20260812 06:19:45.603081  6260 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012520986s
I20260812 06:19:45.603888  6311 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60632
I20260812 06:19:45.614159  6311 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60640:
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:19:45.629263  6470 tablet_service.cc:1511] Processing CreateTablet for tablet 3433a51267c34bc9a65078320f047257 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8933958b23b74e34b138c8ba0d362bc7]), partition=
I20260812 06:19:45.629733  6470 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3433a51267c34bc9a65078320f047257. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:45.632563  6542 tablet_bootstrap.cc:492] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Bootstrap starting.
I20260812 06:19:45.633639  6542 tablet_bootstrap.cc:654] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:45.634924  6542 tablet_bootstrap.cc:492] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: No bootstrap required, opened a new log
I20260812 06:19:45.635062  6542 ts_tablet_manager.cc:1403] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:45.635541  6542 raft_consensus.cc:359] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfea105265784f0facf3355b08bbcf5c" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 44367 } }
I20260812 06:19:45.635669  6542 raft_consensus.cc:385] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:45.635718  6542 raft_consensus.cc:740] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfea105265784f0facf3355b08bbcf5c, State: Initialized, Role: FOLLOWER
I20260812 06:19:45.635870  6542 consensus_queue.cc:260] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [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: "bfea105265784f0facf3355b08bbcf5c" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 44367 } }
I20260812 06:19:45.635988  6542 raft_consensus.cc:399] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:45.636049  6542 raft_consensus.cc:493] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:45.636158  6542 raft_consensus.cc:3060] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:45.637288  6542 raft_consensus.cc:515] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfea105265784f0facf3355b08bbcf5c" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 44367 } }
I20260812 06:19:45.637446  6542 leader_election.cc:304] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [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: bfea105265784f0facf3355b08bbcf5c; no voters: 
I20260812 06:19:45.637699  6542 leader_election.cc:290] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:45.637797  6544 raft_consensus.cc:2804] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:45.638083  6542 ts_tablet_manager.cc:1434] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:45.638079  6544 raft_consensus.cc:697] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 1 LEADER]: Becoming Leader. State: Replica: bfea105265784f0facf3355b08bbcf5c, State: Running, Role: LEADER
I20260812 06:19:45.638336  6524 heartbeater.cc:499] Master 127.6.29.62:37537 was elected leader, sending a full tablet report...
I20260812 06:19:45.638309  6544 consensus_queue.cc:237] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [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: "bfea105265784f0facf3355b08bbcf5c" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 44367 } }
I20260812 06:19:45.641582  6311 catalog_manager.cc:5719] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c reported cstate change: term changed from 0 to 1, leader changed from <none> to bfea105265784f0facf3355b08bbcf5c (127.6.29.1). New cstate: current_term: 1 leader_uuid: "bfea105265784f0facf3355b08bbcf5c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfea105265784f0facf3355b08bbcf5c" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 44367 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:45.724217  6260 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.074s	user 0.020s	sys 0.017s
I20260812 06:19:45.841045  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushMRSOp(3433a51267c34bc9a65078320f047257): perf score=15.086190
I20260812 06:19:46.005156  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushMRSOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.164s	user 0.111s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":260,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":791,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40101,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":2432,"thread_start_us":179,"threads_started":1,"update_count":1500}
I20260812 06:19:46.006484  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling LogGCOp(3433a51267c34bc9a65078320f047257): free 20290830 bytes of WAL
I20260812 06:19:46.006930  6437 log_reader.cc:385] T 3433a51267c34bc9a65078320f047257: removed 2 log segments from log reader
I20260812 06:19:46.007011  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000001 (ops 1-6)
I20260812 06:19:46.007069  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000002 (ops 7-10)
I20260812 06:19:46.013085  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: LogGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:46.013581  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257): 12308960 bytes on disk
I20260812 06:19:46.014266  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.014780  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.040381  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.040998  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.058429  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6393,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.058993  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:46.225672  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.167s	user 0.106s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1017,"lbm_read_time_us":10725,"lbm_reads_lt_1ms":565,"lbm_write_time_us":29860,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":324,"threads_started":5,"update_count":2500}
I20260812 06:19:46.226238  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:46.264806  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.038s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.265376  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.285373  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.285909  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:46.407954  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.122s	user 0.095s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":8322,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25374,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:46.408703  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:46.452924  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.044s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15314,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.453379  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.464182  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.464674  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:46.593958  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.129s	user 0.100s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":9612,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23961,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:19:46.594808  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:46.648329  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.053s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18610,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.649462  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.663532  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.664000  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:46.814985  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.151s	user 0.107s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":11966,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23054,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:19:46.815625  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:46.864351  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.049s	user 0.011s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18716,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.864951  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:46.875663  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.876135  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:47.007776  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.131s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1061,"lbm_read_time_us":9583,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25693,"lbm_writes_lt_1ms":443,"mutex_wait_us":95,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.008353  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:47.049494  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.041s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16059,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.049947  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.061178  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.061614  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:47.197364  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.136s	user 0.110s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1236,"lbm_read_time_us":9766,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30952,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":448,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:19:47.198061  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:47.256675  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.058s	user 0.027s	sys 0.031s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":23207,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.257252  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.268215  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.268709  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushMRSOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:47.318948  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushMRSOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.050s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1456,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2589,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:47.319941  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling LogGCOp(3433a51267c34bc9a65078320f047257): free 112692311 bytes of WAL
I20260812 06:19:47.320218  6437 log_reader.cc:385] T 3433a51267c34bc9a65078320f047257: removed 11 log segments from log reader
I20260812 06:19:47.320274  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000003 (ops 11-15)
I20260812 06:19:47.320312  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000004 (ops 16-20)
I20260812 06:19:47.320408  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000005 (ops 21-25)
I20260812 06:19:47.320521  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000006 (ops 26-30)
I20260812 06:19:47.320577  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000007 (ops 31-35)
I20260812 06:19:47.320631  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000008 (ops 36-40)
I20260812 06:19:47.320688  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000009 (ops 41-45)
I20260812 06:19:47.320739  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000010 (ops 46-50)
I20260812 06:19:47.320791  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000011 (ops 51-55)
I20260812 06:19:47.320843  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000012 (ops 56-60)
I20260812 06:19:47.320896  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000013 (ops 61-65)
I20260812 06:19:47.349195  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: LogGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:47.349856  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257): 462 bytes on disk
I20260812 06:19:47.350422  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.351336  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.365773  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.014s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4266756,"delete_count":0,"lbm_write_time_us":5677,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:19:47.366274  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.379350  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4769,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:47.380059  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:47.579216  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.199s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836370,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":298,"lbm_read_time_us":13722,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32287,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:47.579770  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:47.650496  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.071s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25272,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.650981  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.661770  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.662356  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:47.843616  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.181s	user 0.149s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":54,"lbm_read_time_us":13322,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30309,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:19:47.844298  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:47.907891  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.063s	user 0.022s	sys 0.038s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.908566  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:47.919268  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.919736  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:48.092219  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.172s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":13266,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27463,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:48.093281  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=10.126437
I20260812 06:19:48.137605  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.044s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18552,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.138195  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:48.168700  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.030s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.169194  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:48.184324  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.184937  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:48.374881  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.190s	user 0.133s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733846,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":171,"lbm_read_time_us":13607,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29443,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:19:48.375644  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:48.428297  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.052s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22998,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.428887  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:48.449039  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.020s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.449599  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:48.636056  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.186s	user 0.129s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":15550,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28135,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:48.636842  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:48.693485  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.056s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.694020  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:48.706252  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.706928  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:48.897801  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.191s	user 0.087s	sys 0.096s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":769,"lbm_read_time_us":13947,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30292,"lbm_writes_lt_1ms":543,"mutex_wait_us":339,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:48.898433  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:48.948290  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22207,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.948908  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:48.967022  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.967564  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushMRSOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:49.019325  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushMRSOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.052s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1346,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1985,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:49.020267  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=6.157687
I20260812 06:19:49.049929  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.029s	user 0.020s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13031,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:49.050452  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling LogGCOp(3433a51267c34bc9a65078320f047257): free 145042381 bytes of WAL
I20260812 06:19:49.050730  6437 log_reader.cc:385] T 3433a51267c34bc9a65078320f047257: removed 14 log segments from log reader
I20260812 06:19:49.050801  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000014 (ops 66-70)
I20260812 06:19:49.050894  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000015 (ops 71-75)
I20260812 06:19:49.050936  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000016 (ops 76-80)
I20260812 06:19:49.051003  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000017 (ops 81-84)
I20260812 06:19:49.051044  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000018 (ops 85-89)
I20260812 06:19:49.051070  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000019 (ops 90-94)
I20260812 06:19:49.051127  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000020 (ops 95-99)
I20260812 06:19:49.051173  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000021 (ops 100-104)
I20260812 06:19:49.051211  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000022 (ops 105-109)
I20260812 06:19:49.051254  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000023 (ops 110-114)
I20260812 06:19:49.051298  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000024 (ops 115-119)
I20260812 06:19:49.051339  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000025 (ops 120-124)
I20260812 06:19:49.051378  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000026 (ops 125-129)
I20260812 06:19:49.051419  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000027 (ops 130-134)
I20260812 06:19:49.082974  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: LogGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:49.083405  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257): 507 bytes on disk
I20260812 06:19:49.083873  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.084365  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:49.095757  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.096238  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:49.355196  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.259s	user 0.173s	sys 0.083s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37041197,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1304,"lbm_read_time_us":19297,"lbm_reads_lt_1ms":870,"lbm_write_time_us":44552,"lbm_writes_lt_1ms":843,"mutex_wait_us":356,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":43264,"thread_start_us":79,"threads_started":1,"update_count":4000}
I20260812 06:19:49.356822  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=18.063937
I20260812 06:19:49.416945  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.060s	user 0.045s	sys 0.013s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26708,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.417596  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:49.605093  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.187s	user 0.136s	sys 0.051s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733607,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":425,"lbm_read_time_us":13784,"lbm_reads_lt_1ms":563,"lbm_write_time_us":35026,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:49.605731  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:49.668316  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.062s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19868,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.668906  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:49.685936  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.017s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6407,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.686508  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:49.890640  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.204s	user 0.136s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1046,"lbm_read_time_us":12802,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31482,"lbm_writes_lt_1ms":543,"mutex_wait_us":518,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:49.891311  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:49.953840  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.062s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":28209,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.954411  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:49.979014  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.024s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.979605  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:50.167362  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.188s	user 0.103s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":997,"lbm_read_time_us":13358,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32604,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:19:50.168123  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:50.221783  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.053s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.222291  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:50.234639  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.235425  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:50.434787  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.199s	user 0.135s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":12695,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31036,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:50.435499  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=14.095187
I20260812 06:19:50.489522  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.054s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21824,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.490026  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:50.506637  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.507117  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushMRSOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:50.544719  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushMRSOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.037s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1511,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1901,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:50.545463  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257): 447 bytes on disk
I20260812 06:19:50.545935  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: UndoDeltaBlockGCOp(3433a51267c34bc9a65078320f047257) 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:19:50.546548  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=3.181125
I20260812 06:19:50.573240  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.026s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6939,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:50.573815  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling LogGCOp(3433a51267c34bc9a65078320f047257): free 112692556 bytes of WAL
I20260812 06:19:50.574122  6437 log_reader.cc:385] T 3433a51267c34bc9a65078320f047257: removed 11 log segments from log reader
I20260812 06:19:50.574191  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000028 (ops 135-139)
I20260812 06:19:50.574232  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000029 (ops 140-144)
I20260812 06:19:50.574270  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000030 (ops 145-149)
I20260812 06:19:50.574313  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000031 (ops 150-154)
I20260812 06:19:50.574348  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000032 (ops 155-159)
I20260812 06:19:50.574384  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000033 (ops 160-164)
I20260812 06:19:50.574416  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000034 (ops 165-169)
I20260812 06:19:50.574451  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000035 (ops 170-174)
I20260812 06:19:50.574491  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000036 (ops 175-179)
I20260812 06:19:50.574524  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000037 (ops 180-184)
I20260812 06:19:50.574558  6437 log.cc:1079] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/3433a51267c34bc9a65078320f047257/wal-000000038 (ops 185-189)
I20260812 06:19:50.607527  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: LogGCOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:50.608063  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:50.636488  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.028s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.637046  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=2.188937
I20260812 06:19:50.651410  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.652047  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257): perf score=1.000000
I20260812 06:19:50.908519  6260 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.184s	user 1.953s	sys 0.150s
I20260812 06:19:50.929252  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: MajorDeltaCompactionOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.277s	user 0.163s	sys 0.107s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1745,"lbm_read_time_us":19307,"lbm_reads_lt_1ms":875,"lbm_write_time_us":46031,"lbm_writes_lt_1ms":843,"mutex_wait_us":583,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":38656,"thread_start_us":84,"threads_started":1,"update_count":4000}
I20260812 06:19:50.930032  6525 maintenance_manager.cc:419] P bfea105265784f0facf3355b08bbcf5c: Scheduling FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257): perf score=18.063937
I20260812 06:19:50.976272  6260 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.001s	sys 0.000s
I20260812 06:19:50.976997  6260 tablet_server.cc:179] TabletServer@127.6.29.1:0 shutting down...
I20260812 06:19:50.987936  6437 maintenance_manager.cc:643] P bfea105265784f0facf3355b08bbcf5c: FlushDeltaMemStoresOp(3433a51267c34bc9a65078320f047257) complete. Timing: real 0.058s	user 0.026s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26705,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.988610  6260 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:50.989039  6260 tablet_replica.cc:333] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c: stopping tablet replica
I20260812 06:19:50.989233  6260 raft_consensus.cc:2243] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:50.989424  6260 raft_consensus.cc:2272] T 3433a51267c34bc9a65078320f047257 P bfea105265784f0facf3355b08bbcf5c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.004256  6260 tablet_server.cc:196] TabletServer@127.6.29.1:0 shutdown complete.
I20260812 06:19:51.009375  6260 master.cc:562] Master@127.6.29.62:37537 shutting down...
I20260812 06:19:51.013331  6260 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.013554  6260 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.013648  6260 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4c037112b30b400e981f714626f34603: stopping tablet replica
I20260812 06:19:51.026479  6260 master.cc:584] Master@127.6.29.62:37537 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5691 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:51.121752  6260 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.29.62:36945
I20260812 06:19:51.122196  6260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.124677  6571 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:19:51.124868  6260 server_base.cc:1061] running on GCE node
W20260812 06:19:51.124790  6572 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:51.124677  6575 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:19:51.125290  6260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.125367  6260 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:19:51.125387  6260 hybrid_clock.cc:648] HybridClock initialized: now 1786515591125387 us; error 0 us; skew 500 ppm
I20260812 06:19:51.126309  6260 webserver.cc:533] Webserver started at http://127.6.29.62:40121/ using document root <none> and password file <none>
I20260812 06:19:51.126466  6260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.126513  6260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.126596  6260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.126978  6260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/master-0-root/instance:
uuid: "913118777d7e468e935275b3eb5abe5e"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-44d2"
I20260812 06:19:51.128633  6260 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:51.129611  6584 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:19:51.129848  6260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:51.129925  6260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/master-0-root
uuid: "913118777d7e468e935275b3eb5abe5e"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-44d2"
I20260812 06:19:51.130043  6260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-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:19:51.146536  6260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.146984  6260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.151273  6260 rpc_server.cc:307] RPC server started. Bound to: 127.6.29.62:36945
I20260812 06:19:51.155484  6657 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.29.62:36945 every 8 connection(s)
I20260812 06:19:51.163183  6658 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:19:51.167769  6658 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e: Bootstrap starting.
I20260812 06:19:51.168646  6658 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.169728  6658 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e: No bootstrap required, opened a new log
I20260812 06:19:51.170122  6658 raft_consensus.cc:359] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER }
I20260812 06:19:51.170207  6658 raft_consensus.cc:385] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.170229  6658 raft_consensus.cc:740] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 913118777d7e468e935275b3eb5abe5e, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.170378  6658 consensus_queue.cc:260] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [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: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER }
I20260812 06:19:51.170467  6658 raft_consensus.cc:399] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.170492  6658 raft_consensus.cc:493] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.170532  6658 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.171181  6658 raft_consensus.cc:515] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER }
I20260812 06:19:51.171290  6658 leader_election.cc:304] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [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: 913118777d7e468e935275b3eb5abe5e; no voters: 
I20260812 06:19:51.171435  6658 leader_election.cc:290] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.171588  6663 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.171854  6663 raft_consensus.cc:697] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 1 LEADER]: Becoming Leader. State: Replica: 913118777d7e468e935275b3eb5abe5e, State: Running, Role: LEADER
I20260812 06:19:51.171957  6658 sys_catalog.cc:565] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:51.172066  6663 consensus_queue.cc:237] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [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: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER }
I20260812 06:19:51.172572  6666 sys_catalog.cc:455] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "913118777d7e468e935275b3eb5abe5e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER } }
I20260812 06:19:51.172710  6666 sys_catalog.cc:458] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.173215  6667 sys_catalog.cc:455] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 913118777d7e468e935275b3eb5abe5e. Latest consensus state: current_term: 1 leader_uuid: "913118777d7e468e935275b3eb5abe5e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "913118777d7e468e935275b3eb5abe5e" member_type: VOTER } }
I20260812 06:19:51.173312  6667 sys_catalog.cc:458] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.173403  6673 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:51.174273  6673 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:51.174459  6260 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:51.176237  6673 catalog_manager.cc:1383] Generated new cluster ID: 02913491c0674c538dd9d4f0ed0fd5eb
I20260812 06:19:51.176299  6673 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:51.188880  6673 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:51.189713  6673 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:51.198946  6673 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e: Generated new TSK 0
I20260812 06:19:51.199173  6673 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:51.206765  6260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.208949  6696 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:51.208895  6699 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:19:51.208895  6695 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:19:51.209254  6260 server_base.cc:1061] running on GCE node
I20260812 06:19:51.209517  6260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.209563  6260 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:19:51.209599  6260 hybrid_clock.cc:648] HybridClock initialized: now 1786515591209598 us; error 0 us; skew 500 ppm
I20260812 06:19:51.210428  6260 webserver.cc:533] Webserver started at http://127.6.29.1:41123/ using document root <none> and password file <none>
I20260812 06:19:51.210631  6260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.210695  6260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.210749  6260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.211119  6260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/instance:
uuid: "d86801d346f64e19bf41531759398cac"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-44d2"
I20260812 06:19:51.213697  6260 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:51.214740  6707 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:19:51.215119  6260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:51.215204  6260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root
uuid: "d86801d346f64e19bf41531759398cac"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-44d2"
I20260812 06:19:51.215268  6260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-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:19:51.248153  6260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.248651  6260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.248996  6260 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:51.249547  6260 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:51.249617  6260 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.249676  6260 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:51.249749  6260 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.254515  6260 rpc_server.cc:307] RPC server started. Bound to: 127.6.29.1:36209
I20260812 06:19:51.254840  6805 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.29.1:36209 every 8 connection(s)
I20260812 06:19:51.272468  6806 heartbeater.cc:344] Connected to a master server at 127.6.29.62:36945
I20260812 06:19:51.272696  6806 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:51.272979  6806 heartbeater.cc:507] Master 127.6.29.62:36945 requested a full tablet report, sending...
I20260812 06:19:51.273825  6611 ts_manager.cc:194] Registered new tserver with Master: d86801d346f64e19bf41531759398cac (127.6.29.1:36209)
I20260812 06:19:51.274272  6260 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019066023s
I20260812 06:19:51.274662  6611 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53030
I20260812 06:19:51.282955  6611 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53044:
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:19:51.292093  6746 tablet_service.cc:1511] Processing CreateTablet for tablet 032c71aaf451472b8dffb42228d830b2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1083de56950e43d6b721c7d5891a4c41]), partition=
I20260812 06:19:51.292349  6746 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 032c71aaf451472b8dffb42228d830b2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:51.294317  6823 tablet_bootstrap.cc:492] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Bootstrap starting.
I20260812 06:19:51.295374  6823 tablet_bootstrap.cc:654] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.296577  6823 tablet_bootstrap.cc:492] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: No bootstrap required, opened a new log
I20260812 06:19:51.296690  6823 ts_tablet_manager.cc:1403] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:51.297189  6823 raft_consensus.cc:359] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d86801d346f64e19bf41531759398cac" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 36209 } }
I20260812 06:19:51.297322  6823 raft_consensus.cc:385] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.297372  6823 raft_consensus.cc:740] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d86801d346f64e19bf41531759398cac, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.297533  6823 consensus_queue.cc:260] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [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: "d86801d346f64e19bf41531759398cac" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 36209 } }
I20260812 06:19:51.297634  6823 raft_consensus.cc:399] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.297678  6823 raft_consensus.cc:493] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.297735  6823 raft_consensus.cc:3060] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.298594  6823 raft_consensus.cc:515] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d86801d346f64e19bf41531759398cac" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 36209 } }
I20260812 06:19:51.298719  6823 leader_election.cc:304] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [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: d86801d346f64e19bf41531759398cac; no voters: 
I20260812 06:19:51.298878  6823 leader_election.cc:290] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.299015  6827 raft_consensus.cc:2804] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.299269  6806 heartbeater.cc:499] Master 127.6.29.62:36945 was elected leader, sending a full tablet report...
I20260812 06:19:51.299263  6827 raft_consensus.cc:697] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 1 LEADER]: Becoming Leader. State: Replica: d86801d346f64e19bf41531759398cac, State: Running, Role: LEADER
I20260812 06:19:51.299265  6823 ts_tablet_manager.cc:1434] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:51.299408  6827 consensus_queue.cc:237] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [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: "d86801d346f64e19bf41531759398cac" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 36209 } }
I20260812 06:19:51.300751  6611 catalog_manager.cc:5719] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac reported cstate change: term changed from 0 to 1, leader changed from <none> to d86801d346f64e19bf41531759398cac (127.6.29.1). New cstate: current_term: 1 leader_uuid: "d86801d346f64e19bf41531759398cac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d86801d346f64e19bf41531759398cac" member_type: VOTER last_known_addr { host: "127.6.29.1" port: 36209 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:51.366194  6260 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.019s	sys 0.004s
I20260812 06:19:51.505757  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushMRSOp(032c71aaf451472b8dffb42228d830b2): perf score=19.054940
I20260812 06:19:51.647678  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushMRSOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.142s	user 0.111s	sys 0.028s Metrics: {"bytes_written":9107612,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":971,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34320,"lbm_writes_lt_1ms":679,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1110}
I20260812 06:19:51.648365  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling LogGCOp(032c71aaf451472b8dffb42228d830b2): free 20290830 bytes of WAL
I20260812 06:19:51.648633  6715 log_reader.cc:385] T 032c71aaf451472b8dffb42228d830b2: removed 2 log segments from log reader
I20260812 06:19:51.648679  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000001 (ops 1-6)
I20260812 06:19:51.648711  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000002 (ops 7-10)
I20260812 06:19:51.653306  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: LogGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:51.653664  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:51.663545  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3556,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:51.664180  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:51.811203  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.147s	user 0.085s	sys 0.048s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":11242,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20107,"lbm_writes_lt_1ms":343,"mutex_wait_us":26,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":324,"threads_started":5,"update_count":1500}
I20260812 06:19:51.811846  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:51.858788  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.047s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15717,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.859306  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:51.870241  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3974,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.870855  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:51.996268  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.125s	user 0.083s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":8548,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24561,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:19:51.997295  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:52.039759  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.042s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16512,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.040366  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:52.051146  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.052019  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2): 16411393 bytes on disk
I20260812 06:19:52.052812  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":146,"lbm_reads_lt_1ms":4}
I20260812 06:19:52.053290  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:52.186272  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.133s	user 0.083s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":645,"lbm_read_time_us":10017,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25366,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:19:52.186976  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:52.234570  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.047s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15703,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.235095  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:52.245714  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.246403  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:52.379102  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.132s	user 0.107s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":10780,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25866,"lbm_writes_lt_1ms":443,"mutex_wait_us":329,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:19:52.379806  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:52.434477  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.055s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15145,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.434993  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:52.445683  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.446151  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:52.596623  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.150s	user 0.099s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":11713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22628,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:52.599759  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:52.646260  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.046s	user 0.036s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19858,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.646888  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:52.666404  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.667094  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:52.813542  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.146s	user 0.098s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":11910,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27757,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:19:52.814522  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=10.126437
I20260812 06:19:52.852653  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.037s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15443,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.853266  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:52.869195  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.869771  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushMRSOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:52.897179  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushMRSOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1588,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:52.898221  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling LogGCOp(032c71aaf451472b8dffb42228d830b2): free 112239319 bytes of WAL
I20260812 06:19:52.898684  6715 log_reader.cc:385] T 032c71aaf451472b8dffb42228d830b2: removed 11 log segments from log reader
I20260812 06:19:52.898854  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000003 (ops 11-15)
I20260812 06:19:52.899029  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000004 (ops 16-20)
I20260812 06:19:52.899174  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000005 (ops 21-25)
I20260812 06:19:52.899283  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000006 (ops 26-30)
I20260812 06:19:52.899376  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000007 (ops 31-35)
I20260812 06:19:52.899433  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000008 (ops 36-40)
I20260812 06:19:52.899485  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000009 (ops 41-44)
I20260812 06:19:52.899533  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000010 (ops 45-49)
I20260812 06:19:52.899572  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000011 (ops 50-54)
I20260812 06:19:52.899668  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000012 (ops 55-59)
I20260812 06:19:52.899726  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000013 (ops 60-64)
I20260812 06:19:52.929023  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: LogGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:52.929522  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2): 447 bytes on disk
I20260812 06:19:52.929971  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:52.930444  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=6.157687
I20260812 06:19:52.957957  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.027s	user 0.013s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10134,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:52.958410  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:53.131215  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.173s	user 0.135s	sys 0.037s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":594,"lbm_read_time_us":11979,"lbm_reads_lt_1ms":665,"lbm_write_time_us":34912,"lbm_writes_lt_1ms":643,"mutex_wait_us":117,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19328,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:53.132022  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:53.185936  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.054s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23708,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.186661  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=3.181125
I20260812 06:19:53.202472  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4811,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.202970  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:53.213292  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3786,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.213852  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:53.413784  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.200s	user 0.144s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":280,"lbm_read_time_us":13354,"lbm_reads_lt_1ms":673,"lbm_write_time_us":43356,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":3000}
I20260812 06:19:53.414320  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:53.477337  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.063s	user 0.022s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30165,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.477891  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:53.501709  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.024s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.502168  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:53.512717  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.513329  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:53.684674  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.171s	user 0.141s	sys 0.024s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1059,"lbm_read_time_us":11396,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37250,"lbm_writes_lt_1ms":643,"mutex_wait_us":353,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":3000}
I20260812 06:19:53.685637  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:53.739965  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.054s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.740655  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:53.754626  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.755179  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:53.919740  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.164s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":10842,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35495,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:53.920346  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:53.979399  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.059s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25804,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.979967  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:53.992022  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.992687  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:54.190091  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.197s	user 0.125s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":11539,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36442,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:19:54.190827  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:54.248363  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.057s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24274,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.248944  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushMRSOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:54.286523  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushMRSOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.037s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1395,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1567,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:54.287158  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2): 448 bytes on disk
I20260812 06:19:54.287648  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2) 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:19:54.288259  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=3.181125
I20260812 06:19:54.309648  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.021s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7147,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:54.310132  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling LogGCOp(032c71aaf451472b8dffb42228d830b2): free 121006434 bytes of WAL
I20260812 06:19:54.310359  6715 log_reader.cc:385] T 032c71aaf451472b8dffb42228d830b2: removed 12 log segments from log reader
I20260812 06:19:54.310410  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000014 (ops 65-69)
I20260812 06:19:54.310439  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000015 (ops 70-74)
I20260812 06:19:54.310506  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000016 (ops 75-79)
I20260812 06:19:54.310550  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000017 (ops 80-84)
I20260812 06:19:54.310590  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000018 (ops 85-88)
I20260812 06:19:54.310629  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000019 (ops 89-93)
I20260812 06:19:54.310669  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000020 (ops 94-98)
I20260812 06:19:54.310714  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000021 (ops 99-103)
I20260812 06:19:54.310755  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000022 (ops 104-108)
I20260812 06:19:54.310793  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000023 (ops 109-113)
I20260812 06:19:54.310833  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000024 (ops 114-118)
I20260812 06:19:54.310873  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000025 (ops 119-123)
I20260812 06:19:54.337961  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: LogGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:54.338403  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:54.354478  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.016s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3756,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.355074  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:54.374191  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.019s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.374804  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:54.627573  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.252s	user 0.180s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":244,"lbm_read_time_us":20381,"lbm_reads_lt_1ms":774,"lbm_write_time_us":47797,"lbm_writes_lt_1ms":743,"mutex_wait_us":365,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:19:54.628343  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=18.063937
I20260812 06:19:54.684654  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.056s	user 0.036s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25440,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:54.685215  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:54.699627  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.700206  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:54.868981  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.169s	user 0.145s	sys 0.023s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":13189,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35629,"lbm_writes_lt_1ms":643,"mutex_wait_us":101,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:19:54.869607  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:54.921965  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20227,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.922478  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:54.934928  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.935597  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.102169  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.166s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1202,"lbm_read_time_us":10912,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29977,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:19:55.102847  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=12.110812
I20260812 06:19:55.147816  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":13825382,"delete_count":0,"lbm_write_time_us":20033,"lbm_writes_lt_1ms":340,"reinsert_count":0,"update_count":1685}
I20260812 06:19:55.148468  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=1.196750
I20260812 06:19:55.161787  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.013s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3437,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:19:55.162252  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.329015  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.167s	user 0.108s	sys 0.046s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082494,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":11000,"lbm_reads_lt_1ms":474,"lbm_write_time_us":26127,"lbm_writes_lt_1ms":453,"mutex_wait_us":76,"peak_mem_usage":51099678,"reinsert_count":0,"update_count":2050}
I20260812 06:19:55.329720  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:55.383059  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.053s	user 0.021s	sys 0.025s Metrics: {"bytes_written":15999662,"delete_count":0,"lbm_write_time_us":22123,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:19:55.383570  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:55.404150  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4433,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.404846  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.579890  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.175s	user 0.111s	sys 0.057s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364448,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1184,"lbm_read_time_us":11594,"lbm_reads_lt_1ms":562,"lbm_write_time_us":28458,"lbm_writes_lt_1ms":533,"mutex_wait_us":353,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2450}
I20260812 06:19:55.580677  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:55.631364  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.050s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19250,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.631887  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:55.642802  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.643435  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.830729  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.187s	user 0.135s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":11463,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31170,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:19:55.831543  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=14.095187
I20260812 06:19:55.887094  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.055s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25339,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.887652  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=2.188937
I20260812 06:19:55.898757  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.899246  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushMRSOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.934252  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushMRSOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.035s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316414,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":335,"dirs.run_wall_time_us":1584,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1807,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:55.934965  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling LogGCOp(032c71aaf451472b8dffb42228d830b2): free 132571575 bytes of WAL
I20260812 06:19:55.935217  6715 log_reader.cc:385] T 032c71aaf451472b8dffb42228d830b2: removed 13 log segments from log reader
I20260812 06:19:55.935264  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000026 (ops 124-128)
I20260812 06:19:55.935293  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000027 (ops 129-133)
I20260812 06:19:55.935310  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000028 (ops 134-138)
I20260812 06:19:55.935372  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000029 (ops 139-142)
I20260812 06:19:55.935418  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000030 (ops 143-147)
I20260812 06:19:55.935470  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000031 (ops 148-152)
I20260812 06:19:55.935527  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000032 (ops 153-157)
I20260812 06:19:55.935547  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000033 (ops 158-162)
I20260812 06:19:55.935564  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000034 (ops 163-166)
I20260812 06:19:55.935608  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000035 (ops 167-171)
I20260812 06:19:55.935649  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000036 (ops 172-176)
I20260812 06:19:55.935696  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000037 (ops 177-181)
I20260812 06:19:55.935734  6715 log.cc:1079] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: Deleting log segment in path: /tmp/dist-test-taskOwT9KF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585420058-6260-0/minicluster-data/ts-0-root/wals/032c71aaf451472b8dffb42228d830b2/wal-000000038 (ops 182-186)
I20260812 06:19:55.966022  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: LogGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:55.966496  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2): 492 bytes on disk
I20260812 06:19:55.967303  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: UndoDeltaBlockGCOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.968113  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=5.165500
I20260812 06:19:55.990582  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":9761,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:55.991041  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:55.996591  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.005s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":1742,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:55.997076  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:56.242542  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.245s	user 0.152s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1089,"lbm_read_time_us":17250,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38559,"lbm_writes_lt_1ms":743,"mutex_wait_us":341,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:19:56.243392  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2): perf score=18.063937
I20260812 06:19:56.310961  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: FlushDeltaMemStoresOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.067s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28927,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.311515  6808 maintenance_manager.cc:419] P d86801d346f64e19bf41531759398cac: Scheduling MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2): perf score=1.000000
I20260812 06:19:56.327286  6260 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.961s	user 1.813s	sys 0.128s
I20260812 06:19:56.393963  6260 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.066s	user 0.002s	sys 0.000s
I20260812 06:19:56.394512  6260 tablet_server.cc:179] TabletServer@127.6.29.1:0 shutting down...
I20260812 06:19:56.470137  6715 maintenance_manager.cc:643] P d86801d346f64e19bf41531759398cac: MajorDeltaCompactionOp(032c71aaf451472b8dffb42228d830b2) complete. Timing: real 0.158s	user 0.126s	sys 0.032s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":502,"lbm_read_time_us":13217,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27841,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":66944,"update_count":2500}
I20260812 06:19:56.470752  6260 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:56.471081  6260 tablet_replica.cc:333] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac: stopping tablet replica
I20260812 06:19:56.471235  6260 raft_consensus.cc:2243] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.471421  6260 raft_consensus.cc:2272] T 032c71aaf451472b8dffb42228d830b2 P d86801d346f64e19bf41531759398cac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.476145  6260 tablet_server.cc:196] TabletServer@127.6.29.1:0 shutdown complete.
I20260812 06:19:56.515964  6260 master.cc:562] Master@127.6.29.62:36945 shutting down...
I20260812 06:19:56.519415  6260 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.519619  6260 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.519706  6260 tablet_replica.cc:333] T 00000000000000000000000000000000 P 913118777d7e468e935275b3eb5abe5e: stopping tablet replica
I20260812 06:19:56.532195  6260 master.cc:584] Master@127.6.29.62:36945 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5500 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11193 ms total)

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