[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:15.142912 28331 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.170.254:38479
I20260812 06:20:15.143989 28331 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:15.144649 28331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:15.151510 28331 server_base.cc:1061] running on GCE node
W20260812 06:20:15.151595 28336 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:15.151506 28337 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:20:15.151821 28339 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:15.152359 28331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:15.152499 28331 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:15.152530 28331 hybrid_clock.cc:648] HybridClock initialized: now 1786515615152529 us; error 0 us; skew 500 ppm
I20260812 06:20:15.154474 28331 webserver.cc:533] Webserver started at http://127.27.170.254:37405/ using document root <none> and password file <none>
I20260812 06:20:15.155009 28331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:15.155067 28331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:15.155272 28331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:15.156905 28331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/master-0-root/instance:
uuid: "4f454379cd78463dbb218085de4ab83f"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-srgv"
I20260812 06:20:15.160682 28331 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:15.163151 28344 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.164216 28331 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:20:15.164341 28331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/master-0-root
uuid: "4f454379cd78463dbb218085de4ab83f"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-srgv"
I20260812 06:20:15.164448 28331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:15.203925 28331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.204667 28331 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:15.204877 28331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.212730 28331 rpc_server.cc:307] RPC server started. Bound to: 127.27.170.254:38479
I20260812 06:20:15.212739 28403 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.170.254:38479 every 8 connection(s)
I20260812 06:20:15.215070 28405 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:15.220609 28405 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: Bootstrap starting.
I20260812 06:20:15.223170 28405 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.224195 28405 log.cc:826] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:15.226065 28405 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: No bootstrap required, opened a new log
I20260812 06:20:15.228986 28405 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER }
I20260812 06:20:15.229166 28405 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.229207 28405 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4f454379cd78463dbb218085de4ab83f, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.229988 28405 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [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: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER }
I20260812 06:20:15.230165 28405 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.230268 28405 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.230427 28405 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.231330 28405 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER }
I20260812 06:20:15.231822 28405 leader_election.cc:304] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [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: 4f454379cd78463dbb218085de4ab83f; no voters: 
I20260812 06:20:15.232208 28405 leader_election.cc:290] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.232353 28409 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.232635 28409 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 1 LEADER]: Becoming Leader. State: Replica: 4f454379cd78463dbb218085de4ab83f, State: Running, Role: LEADER
I20260812 06:20:15.233129 28409 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [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: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER }
I20260812 06:20:15.233327 28405 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:15.235224 28410 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4f454379cd78463dbb218085de4ab83f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER } }
I20260812 06:20:15.235208 28411 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4f454379cd78463dbb218085de4ab83f. Latest consensus state: current_term: 1 leader_uuid: "4f454379cd78463dbb218085de4ab83f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f454379cd78463dbb218085de4ab83f" member_type: VOTER } }
I20260812 06:20:15.235360 28410 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.235360 28411 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.235672 28331 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:15.237772 28426 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:15.237840 28426 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:15.237918 28425 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:15.238660 28425 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:15.243558 28425 catalog_manager.cc:1383] Generated new cluster ID: 750bc1c262a147c8a04864fafe985a73
I20260812 06:20:15.243637 28425 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:15.265771 28425 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:15.267017 28425 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:15.292871 28425 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: Generated new TSK 0
I20260812 06:20:15.293692 28425 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:15.300639 28331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:15.303399 28435 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:15.303369 28431 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:15.303378 28433 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:15.303967 28331 server_base.cc:1061] running on GCE node
I20260812 06:20:15.304157 28331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:15.304208 28331 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:15.304231 28331 hybrid_clock.cc:648] HybridClock initialized: now 1786515615304231 us; error 0 us; skew 500 ppm
I20260812 06:20:15.305184 28331 webserver.cc:533] Webserver started at http://127.27.170.193:41721/ using document root <none> and password file <none>
I20260812 06:20:15.305362 28331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:15.305454 28331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:15.305539 28331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:15.306030 28331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/instance:
uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-srgv"
I20260812 06:20:15.307900 28331 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:15.309018 28440 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.309288 28331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:15.309365 28331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root
uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-srgv"
I20260812 06:20:15.309475 28331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:15.329528 28331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.330027 28331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.330605 28331 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:15.331544 28331 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:15.331595 28331 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.331667 28331 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:15.331717 28331 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.338581 28331 rpc_server.cc:307] RPC server started. Bound to: 127.27.170.193:40167
I20260812 06:20:15.338614 28506 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.170.193:40167 every 8 connection(s)
I20260812 06:20:15.349133 28508 heartbeater.cc:344] Connected to a master server at 127.27.170.254:38479
I20260812 06:20:15.349488 28508 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:15.349961 28508 heartbeater.cc:507] Master 127.27.170.254:38479 requested a full tablet report, sending...
I20260812 06:20:15.351449 28367 ts_manager.cc:194] Registered new tserver with Master: aa42d0f3ad8e4f53af6d1eaa62cd9391 (127.27.170.193:40167)
I20260812 06:20:15.351682 28331 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012425888s
I20260812 06:20:15.353012 28367 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49734
I20260812 06:20:15.362119 28367 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49746:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:15.381902 28469 tablet_service.cc:1511] Processing CreateTablet for tablet 43297fce50ab40d8a8d061652f1cb45c (DEFAULT_TABLE table=heavy-update-compaction-test [id=106069dc6bb74f4dbe18b8f9eb17e8b7]), partition=
I20260812 06:20:15.382431 28469 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 43297fce50ab40d8a8d061652f1cb45c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:15.385615 28520 tablet_bootstrap.cc:492] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Bootstrap starting.
I20260812 06:20:15.386795 28520 tablet_bootstrap.cc:654] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.388026 28520 tablet_bootstrap.cc:492] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: No bootstrap required, opened a new log
I20260812 06:20:15.388167 28520 ts_tablet_manager.cc:1403] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:15.388628 28520 raft_consensus.cc:359] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 40167 } }
I20260812 06:20:15.388767 28520 raft_consensus.cc:385] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.388836 28520 raft_consensus.cc:740] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aa42d0f3ad8e4f53af6d1eaa62cd9391, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.389008 28520 consensus_queue.cc:260] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [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: "aa42d0f3ad8e4f53af6d1eaa62cd9391" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 40167 } }
I20260812 06:20:15.389117 28520 raft_consensus.cc:399] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.389166 28520 raft_consensus.cc:493] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.389221 28520 raft_consensus.cc:3060] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.390239 28520 raft_consensus.cc:515] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 40167 } }
I20260812 06:20:15.390440 28520 leader_election.cc:304] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [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: aa42d0f3ad8e4f53af6d1eaa62cd9391; no voters: 
I20260812 06:20:15.390745 28520 leader_election.cc:290] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.390846 28522 raft_consensus.cc:2804] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.391037 28522 raft_consensus.cc:697] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 1 LEADER]: Becoming Leader. State: Replica: aa42d0f3ad8e4f53af6d1eaa62cd9391, State: Running, Role: LEADER
I20260812 06:20:15.391161 28520 ts_tablet_manager.cc:1434] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:15.391258 28522 consensus_queue.cc:237] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [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: "aa42d0f3ad8e4f53af6d1eaa62cd9391" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 40167 } }
I20260812 06:20:15.391541 28508 heartbeater.cc:499] Master 127.27.170.254:38479 was elected leader, sending a full tablet report...
I20260812 06:20:15.394269 28367 catalog_manager.cc:5719] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 reported cstate change: term changed from 0 to 1, leader changed from <none> to aa42d0f3ad8e4f53af6d1eaa62cd9391 (127.27.170.193). New cstate: current_term: 1 leader_uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa42d0f3ad8e4f53af6d1eaa62cd9391" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 40167 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:15.463095 28331 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.023s	sys 0.002s
I20260812 06:20:15.589818 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c): perf score=15.086190
I20260812 06:20:15.754683 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.164s	user 0.107s	sys 0.044s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":342,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":979,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37315,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":218,"threads_started":1,"update_count":1450}
I20260812 06:20:15.755986 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling LogGCOp(43297fce50ab40d8a8d061652f1cb45c): free 20743880 bytes of WAL
I20260812 06:20:15.756373 28445 log_reader.cc:385] T 43297fce50ab40d8a8d061652f1cb45c: removed 2 log segments from log reader
I20260812 06:20:15.756458 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000001 (ops 1-6)
I20260812 06:20:15.756531 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000002 (ops 7-11)
I20260812 06:20:15.762223 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: LogGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:15.762707 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c): 12719216 bytes on disk
I20260812 06:20:15.763482 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.763972 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:15.793481 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.029s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.793970 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:15.809083 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.809834 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:15.973799 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.164s	user 0.121s	sys 0.041s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364567,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":593,"lbm_read_time_us":10394,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30036,"lbm_writes_lt_1ms":533,"mutex_wait_us":23,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":339,"threads_started":5,"update_count":2450}
I20260812 06:20:15.974341 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:16.011022 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.037s	user 0.009s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14725,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.011513 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.026794 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.027392 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:16.162035 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.134s	user 0.113s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1333,"lbm_read_time_us":9994,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24752,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:16.162806 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:16.204934 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.042s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18736,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.205560 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.217609 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.218119 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:16.355006 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.137s	user 0.121s	sys 0.016s 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":158,"lbm_read_time_us":11153,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23084,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36736,"update_count":2000}
I20260812 06:20:16.355680 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:16.404829 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.049s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17934,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.405450 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.416671 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.419750 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:16.565579 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.146s	user 0.104s	sys 0.039s 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":670,"lbm_read_time_us":9767,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23707,"lbm_writes_lt_1ms":443,"mutex_wait_us":348,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:16.568009 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:16.609649 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.041s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18580,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.610234 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.630007 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.630487 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:16.750149 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.119s	user 0.095s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":7528,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23520,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:16.751861 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=11.118625
I20260812 06:20:16.783527 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.031s	user 0.004s	sys 0.025s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13964,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.784086 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.797149 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4722,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.797668 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:16.924093 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.126s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":7626,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26008,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:16.924759 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:16.973434 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.048s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14967,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.974062 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:16.991261 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.991886 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:17.033661 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.042s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":289,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1501,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:17.034623 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling LogGCOp(43297fce50ab40d8a8d061652f1cb45c): free 112239312 bytes of WAL
I20260812 06:20:17.034861 28445 log_reader.cc:385] T 43297fce50ab40d8a8d061652f1cb45c: removed 11 log segments from log reader
I20260812 06:20:17.034905 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000003 (ops 12-16)
I20260812 06:20:17.034961 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000004 (ops 17-21)
I20260812 06:20:17.035009 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000005 (ops 22-26)
I20260812 06:20:17.035085 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000006 (ops 27-30)
I20260812 06:20:17.035132 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000007 (ops 31-35)
I20260812 06:20:17.035197 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000008 (ops 36-40)
I20260812 06:20:17.035233 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000009 (ops 41-45)
I20260812 06:20:17.035271 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000010 (ops 46-50)
I20260812 06:20:17.035312 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000011 (ops 51-55)
I20260812 06:20:17.035351 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000012 (ops 56-60)
I20260812 06:20:17.035394 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000013 (ops 61-65)
I20260812 06:20:17.060904 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: LogGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:17.061558 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c): 447 bytes on disk
I20260812 06:20:17.062088 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.062583 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=3.181125
I20260812 06:20:17.083369 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.021s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4656,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.083863 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:17.097329 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5048,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.097950 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:17.288618 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.190s	user 0.134s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":899,"lbm_read_time_us":12283,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31438,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:20:17.289347 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:17.352419 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.063s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23841,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.353088 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:17.363878 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3923,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.364595 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:17.535928 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.171s	user 0.131s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":789,"lbm_read_time_us":12495,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28890,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:20:17.536568 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:17.598068 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.061s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22836,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.598685 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:17.609896 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.610430 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:17.800303 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.190s	user 0.109s	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":221,"lbm_read_time_us":13681,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33223,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:20:17.800928 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:17.872944 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.072s	user 0.029s	sys 0.039s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":29735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.873715 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:17.888258 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.888725 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:18.076922 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.188s	user 0.119s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1148,"lbm_read_time_us":13598,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33642,"lbm_writes_lt_1ms":543,"mutex_wait_us":498,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:18.077589 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=11.118625
I20260812 06:20:18.116007 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":16597,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.116627 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.130280 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4962,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.130995 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:18.297914 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.167s	user 0.119s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":7866,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26212,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:18.298682 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:18.352978 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.054s	user 0.045s	sys 0.004s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23210,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.353655 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.365140 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.365847 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:18.519073 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.153s	user 0.129s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":898,"lbm_read_time_us":10610,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29986,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:20:18.519833 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=11.118625
I20260812 06:20:18.560976 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17625,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.561720 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.576332 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.014s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.576910 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:18.616676 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.040s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1504,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1702,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:18.617695 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c): 483 bytes on disk
I20260812 06:20:18.618209 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.618717 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=3.181125
I20260812 06:20:18.637559 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7135,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.638036 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling LogGCOp(43297fce50ab40d8a8d061652f1cb45c): free 132571314 bytes of WAL
I20260812 06:20:18.638273 28445 log_reader.cc:385] T 43297fce50ab40d8a8d061652f1cb45c: removed 13 log segments from log reader
I20260812 06:20:18.638317 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000014 (ops 66-70)
I20260812 06:20:18.638347 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000015 (ops 71-75)
I20260812 06:20:18.638410 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000016 (ops 76-80)
I20260812 06:20:18.638445 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000017 (ops 81-85)
I20260812 06:20:18.638486 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000018 (ops 86-90)
I20260812 06:20:18.638512 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000019 (ops 91-95)
I20260812 06:20:18.638551 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000020 (ops 96-100)
I20260812 06:20:18.638592 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000021 (ops 101-104)
I20260812 06:20:18.638631 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000022 (ops 105-109)
I20260812 06:20:18.638672 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000023 (ops 110-114)
I20260812 06:20:18.638711 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000024 (ops 115-119)
I20260812 06:20:18.638760 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000025 (ops 120-124)
I20260812 06:20:18.638803 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000026 (ops 125-128)
I20260812 06:20:18.666311 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: LogGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:18.666723 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.680656 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:20:18.681208 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.691520 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:18.691983 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:18.879621 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.187s	user 0.144s	sys 0.043s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979850,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":792,"lbm_read_time_us":12781,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39164,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:18.880154 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:18.925076 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.045s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19093,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:18.925671 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.949275 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.949805 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:18.960700 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.961135 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:19.126195 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.165s	user 0.141s	sys 0.023s 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":177,"lbm_read_time_us":11970,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35891,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":57856,"update_count":3000}
I20260812 06:20:19.129279 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:19.175294 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.045s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20188,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.176015 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:19.193501 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.194141 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:19.346271 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.152s	user 0.117s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":588,"lbm_read_time_us":8388,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29781,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:20:19.347095 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:19.403141 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.056s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24463,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.403755 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:19.556382 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.152s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":308,"lbm_read_time_us":9359,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27073,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.557031 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:19.607851 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.051s	user 0.039s	sys 0.003s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19521,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.608639 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:19.622015 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.622489 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:19.798673 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.176s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":12443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31786,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:19.799415 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=11.118625
I20260812 06:20:19.838171 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.039s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16548,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.838825 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:19.853678 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5487,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.854243 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:19.983124 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.129s	user 0.112s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":7080,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27086,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:20:19.983868 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=10.126437
I20260812 06:20:20.014930 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13672,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.015496 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:20.026026 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.026508 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:20.059405 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushMRSOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1905,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:20.060117 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling LogGCOp(43297fce50ab40d8a8d061652f1cb45c): free 120553643 bytes of WAL
I20260812 06:20:20.060364 28445 log_reader.cc:385] T 43297fce50ab40d8a8d061652f1cb45c: removed 12 log segments from log reader
I20260812 06:20:20.060410 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000027 (ops 129-133)
I20260812 06:20:20.060441 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000028 (ops 134-138)
I20260812 06:20:20.060505 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000029 (ops 139-143)
I20260812 06:20:20.060546 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000030 (ops 144-148)
I20260812 06:20:20.060590 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000031 (ops 149-153)
I20260812 06:20:20.060652 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000032 (ops 154-158)
I20260812 06:20:20.060709 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000033 (ops 159-162)
I20260812 06:20:20.060751 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000034 (ops 163-167)
I20260812 06:20:20.060791 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000035 (ops 168-172)
I20260812 06:20:20.060830 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000036 (ops 173-177)
I20260812 06:20:20.060870 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000037 (ops 178-182)
I20260812 06:20:20.060909 28445 log.cc:1079] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/43297fce50ab40d8a8d061652f1cb45c/wal-000000038 (ops 183-186)
I20260812 06:20:20.087060 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: LogGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:20.087759 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=4.173312
I20260812 06:20:20.106140 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":5538512,"delete_count":0,"lbm_write_time_us":7534,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:20:20.106645 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.196750
I20260812 06:20:20.118033 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:20:20.118482 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c): 472 bytes on disk
I20260812 06:20:20.119014 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: UndoDeltaBlockGCOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.119686 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:20.285682 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.166s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877306,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1020,"lbm_read_time_us":11977,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34022,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:20.286444 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=14.095187
I20260812 06:20:20.335717 28331 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.872s	user 1.780s	sys 0.181s
I20260812 06:20:20.339037 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.052s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22174,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.339588 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c): perf score=2.188937
I20260812 06:20:20.356062 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: FlushDeltaMemStoresOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:20:20.356653 28509 maintenance_manager.cc:419] P aa42d0f3ad8e4f53af6d1eaa62cd9391: Scheduling MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c): perf score=1.000000
I20260812 06:20:20.399296 28331 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.063s	user 0.002s	sys 0.000s
I20260812 06:20:20.399959 28331 tablet_server.cc:179] TabletServer@127.27.170.193:0 shutting down...
I20260812 06:20:20.484367 28445 maintenance_manager.cc:643] P aa42d0f3ad8e4f53af6d1eaa62cd9391: MajorDeltaCompactionOp(43297fce50ab40d8a8d061652f1cb45c) complete. Timing: real 0.127s	user 0.091s	sys 0.036s Metrics: {"cfile_cache_hit":381,"cfile_cache_hit_bytes":15589546,"cfile_cache_miss":151,"cfile_cache_miss_bytes":9185141,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":4471,"lbm_reads_lt_1ms":183,"lbm_write_time_us":27651,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:20:20.485184 28331 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:20.485600 28331 tablet_replica.cc:333] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391: stopping tablet replica
I20260812 06:20:20.485852 28331 raft_consensus.cc:2243] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.486095 28331 raft_consensus.cc:2272] T 43297fce50ab40d8a8d061652f1cb45c P aa42d0f3ad8e4f53af6d1eaa62cd9391 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.501298 28331 tablet_server.cc:196] TabletServer@127.27.170.193:0 shutdown complete.
I20260812 06:20:20.530622 28331 master.cc:562] Master@127.27.170.254:38479 shutting down...
I20260812 06:20:20.535284 28331 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.535504 28331 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.535595 28331 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4f454379cd78463dbb218085de4ab83f: stopping tablet replica
I20260812 06:20:20.548046 28331 master.cc:584] Master@127.27.170.254:38479 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5496 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:20.638593 28331 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.170.254:39767
I20260812 06:20:20.638973 28331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.641001 28540 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:20:20.640967 28542 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.641114 28331 server_base.cc:1061] running on GCE node
W20260812 06:20:20.640967 28539 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.641402 28331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.641497 28331 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.641530 28331 hybrid_clock.cc:648] HybridClock initialized: now 1786515620641530 us; error 0 us; skew 500 ppm
I20260812 06:20:20.642395 28331 webserver.cc:533] Webserver started at http://127.27.170.254:35147/ using document root <none> and password file <none>
I20260812 06:20:20.642583 28331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.642652 28331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.642735 28331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.643162 28331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/master-0-root/instance:
uuid: "7936169553e040ff807715bd8198efcf"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-srgv"
I20260812 06:20:20.644735 28331 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:20.645758 28547 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.646029 28331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:20.646131 28331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/master-0-root
uuid: "7936169553e040ff807715bd8198efcf"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-srgv"
I20260812 06:20:20.646224 28331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.651304 28331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.651674 28331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.656010 28331 rpc_server.cc:307] RPC server started. Bound to: 127.27.170.254:39767
I20260812 06:20:20.658174 28601 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.170.254:39767 every 8 connection(s)
I20260812 06:20:20.666896 28602 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.671736 28602 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf: Bootstrap starting.
I20260812 06:20:20.672576 28602 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.673774 28602 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf: No bootstrap required, opened a new log
I20260812 06:20:20.674141 28602 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7936169553e040ff807715bd8198efcf" member_type: VOTER }
I20260812 06:20:20.674238 28602 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.674263 28602 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7936169553e040ff807715bd8198efcf, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.674368 28602 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [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: "7936169553e040ff807715bd8198efcf" member_type: VOTER }
I20260812 06:20:20.674425 28602 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.674448 28602 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.674476 28602 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.675120 28602 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7936169553e040ff807715bd8198efcf" member_type: VOTER }
I20260812 06:20:20.675243 28602 leader_election.cc:304] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [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: 7936169553e040ff807715bd8198efcf; no voters: 
I20260812 06:20:20.675414 28602 leader_election.cc:290] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.675613 28605 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.675870 28605 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 1 LEADER]: Becoming Leader. State: Replica: 7936169553e040ff807715bd8198efcf, State: Running, Role: LEADER
I20260812 06:20:20.676007 28602 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:20.676016 28605 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [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: "7936169553e040ff807715bd8198efcf" member_type: VOTER }
I20260812 06:20:20.676541 28606 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7936169553e040ff807715bd8198efcf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7936169553e040ff807715bd8198efcf" member_type: VOTER } }
I20260812 06:20:20.676610 28607 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7936169553e040ff807715bd8198efcf. Latest consensus state: current_term: 1 leader_uuid: "7936169553e040ff807715bd8198efcf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7936169553e040ff807715bd8198efcf" member_type: VOTER } }
I20260812 06:20:20.676749 28607 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.676719 28606 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.677302 28613 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:20.678197 28613 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:20.678452 28331 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:20.680194 28613 catalog_manager.cc:1383] Generated new cluster ID: 57da89c6606d4d76a357909fed2b7580
I20260812 06:20:20.680258 28613 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:20.699679 28613 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:20.700240 28613 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:20.712224 28613 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf: Generated new TSK 0
I20260812 06:20:20.712431 28613 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:20.743382 28331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.745563 28625 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.745615 28331 server_base.cc:1061] running on GCE node
W20260812 06:20:20.745564 28623 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.745623 28627 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.745977 28331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.746022 28331 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.746063 28331 hybrid_clock.cc:648] HybridClock initialized: now 1786515620746062 us; error 0 us; skew 500 ppm
I20260812 06:20:20.746932 28331 webserver.cc:533] Webserver started at http://127.27.170.193:34915/ using document root <none> and password file <none>
I20260812 06:20:20.747118 28331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.747202 28331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.747303 28331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.747716 28331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/instance:
uuid: "e774eeb284644696baae65ebaee778e4"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-srgv"
I20260812 06:20:20.749287 28331 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:20.750366 28632 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.750636 28331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:20.750738 28331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root
uuid: "e774eeb284644696baae65ebaee778e4"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-srgv"
I20260812 06:20:20.750824 28331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.770006 28331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.770447 28331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.770797 28331 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:20.771286 28331 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:20.771348 28331 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.771404 28331 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:20.771450 28331 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.776171 28331 rpc_server.cc:307] RPC server started. Bound to: 127.27.170.193:38611
I20260812 06:20:20.776772 28696 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.170.193:38611 every 8 connection(s)
I20260812 06:20:20.781616 28697 heartbeater.cc:344] Connected to a master server at 127.27.170.254:39767
I20260812 06:20:20.781755 28697 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:20.781996 28697 heartbeater.cc:507] Master 127.27.170.254:39767 requested a full tablet report, sending...
I20260812 06:20:20.782652 28564 ts_manager.cc:194] Registered new tserver with Master: e774eeb284644696baae65ebaee778e4 (127.27.170.193:38611)
I20260812 06:20:20.783366 28564 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47420
I20260812 06:20:20.783520 28331 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006678592s
I20260812 06:20:20.790426 28564 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47434:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:20.799233 28660 tablet_service.cc:1511] Processing CreateTablet for tablet 333d2c43672b46b1bc603d7b46eb9335 (DEFAULT_TABLE table=heavy-update-compaction-test [id=73a6435c1da840b4a4b0c6857bcea53f]), partition=
I20260812 06:20:20.799540 28660 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 333d2c43672b46b1bc603d7b46eb9335. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.801748 28709 tablet_bootstrap.cc:492] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Bootstrap starting.
I20260812 06:20:20.802631 28709 tablet_bootstrap.cc:654] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.803691 28709 tablet_bootstrap.cc:492] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: No bootstrap required, opened a new log
I20260812 06:20:20.803783 28709 ts_tablet_manager.cc:1403] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:20.804289 28709 raft_consensus.cc:359] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e774eeb284644696baae65ebaee778e4" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 38611 } }
I20260812 06:20:20.804407 28709 raft_consensus.cc:385] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.804451 28709 raft_consensus.cc:740] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e774eeb284644696baae65ebaee778e4, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.804611 28709 consensus_queue.cc:260] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [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: "e774eeb284644696baae65ebaee778e4" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 38611 } }
I20260812 06:20:20.804739 28709 raft_consensus.cc:399] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.804795 28709 raft_consensus.cc:493] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.804852 28709 raft_consensus.cc:3060] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.805709 28709 raft_consensus.cc:515] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e774eeb284644696baae65ebaee778e4" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 38611 } }
I20260812 06:20:20.805832 28709 leader_election.cc:304] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [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: e774eeb284644696baae65ebaee778e4; no voters: 
I20260812 06:20:20.805991 28709 leader_election.cc:290] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.806151 28711 raft_consensus.cc:2804] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.806337 28709 ts_tablet_manager.cc:1434] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:20.806358 28697 heartbeater.cc:499] Master 127.27.170.254:39767 was elected leader, sending a full tablet report...
I20260812 06:20:20.806371 28711 raft_consensus.cc:697] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 1 LEADER]: Becoming Leader. State: Replica: e774eeb284644696baae65ebaee778e4, State: Running, Role: LEADER
I20260812 06:20:20.806581 28711 consensus_queue.cc:237] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [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: "e774eeb284644696baae65ebaee778e4" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 38611 } }
I20260812 06:20:20.808076 28564 catalog_manager.cc:5719] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 reported cstate change: term changed from 0 to 1, leader changed from <none> to e774eeb284644696baae65ebaee778e4 (127.27.170.193). New cstate: current_term: 1 leader_uuid: "e774eeb284644696baae65ebaee778e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e774eeb284644696baae65ebaee778e4" member_type: VOTER last_known_addr { host: "127.27.170.193" port: 38611 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:20.867470 28331 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.023s	sys 0.000s
I20260812 06:20:21.027308 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335): perf score=19.054940
I20260812 06:20:21.183873 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.156s	user 0.121s	sys 0.031s Metrics: {"bytes_written":13743322,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":911,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42740,"lbm_writes_lt_1ms":802,"mutex_wait_us":1679,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1675}
I20260812 06:20:21.184644 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 20743880 bytes of WAL
I20260812 06:20:21.184875 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 2 log segments from log reader
I20260812 06:20:21.184933 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000001 (ops 1-6)
I20260812 06:20:21.184978 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000002 (ops 7-11)
I20260812 06:20:21.190310 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:21.190663 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.196750
I20260812 06:20:21.207659 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.017s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2666783,"delete_count":0,"lbm_write_time_us":2724,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:20:21.208146 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:21.217749 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3530,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.218171 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335): 16821649 bytes on disk
I20260812 06:20:21.218580 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.218976 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:21.380312 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.161s	user 0.108s	sys 0.053s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405505,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":851,"lbm_read_time_us":11390,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30427,"lbm_writes_lt_1ms":533,"mutex_wait_us":87,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":339,"threads_started":5,"update_count":2450}
I20260812 06:20:21.381207 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=11.118625
I20260812 06:20:21.422204 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.041s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17329,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.422884 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:21.449100 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.026s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5570,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.449609 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:21.460297 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.460763 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:21.621312 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.160s	user 0.105s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815792,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":369,"lbm_read_time_us":10238,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29635,"lbm_writes_lt_1ms":543,"mutex_wait_us":95,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:20:21.621903 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:21.674170 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.052s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.674638 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:21.687430 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.688026 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:21.889736 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.201s	user 0.104s	sys 0.096s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":15123,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32455,"lbm_writes_lt_1ms":543,"mutex_wait_us":423,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:21.890513 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:21.945596 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.055s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23561,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.946290 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:22.090303 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.144s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":912,"lbm_read_time_us":10587,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23309,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:20:22.090965 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:22.149259 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.058s	user 0.048s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26571,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.149861 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:22.162274 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.162830 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:22.348726 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.186s	user 0.110s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":562,"lbm_read_time_us":10673,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29152,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23808,"update_count":2500}
I20260812 06:20:22.349465 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:22.401857 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.052s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19747,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.402483 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:22.419056 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.419715 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:22.453100 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1548,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2259,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:22.453820 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 120553338 bytes of WAL
I20260812 06:20:22.454056 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 12 log segments from log reader
I20260812 06:20:22.454118 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000003 (ops 12-16)
I20260812 06:20:22.454172 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000004 (ops 17-21)
I20260812 06:20:22.454211 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000005 (ops 22-26)
I20260812 06:20:22.454252 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000006 (ops 27-30)
I20260812 06:20:22.454293 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000007 (ops 31-35)
I20260812 06:20:22.454332 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000008 (ops 36-40)
I20260812 06:20:22.454370 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000009 (ops 41-44)
I20260812 06:20:22.454411 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000010 (ops 45-49)
I20260812 06:20:22.454449 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000011 (ops 50-54)
I20260812 06:20:22.454489 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000012 (ops 55-59)
I20260812 06:20:22.454528 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000013 (ops 60-64)
I20260812 06:20:22.454568 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000014 (ops 65-69)
I20260812 06:20:22.483013 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:22.483404 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335): 446 bytes on disk
I20260812 06:20:22.483843 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.484337 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:22.508122 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.508622 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:22.519493 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.519953 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:22.759555 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.239s	user 0.181s	sys 0.058s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1057,"lbm_read_time_us":17677,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37679,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28160,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:20:22.760385 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=18.063937
I20260812 06:20:22.827186 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.067s	user 0.033s	sys 0.029s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29117,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.827680 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:22.838601 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.839444 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:23.073305 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.234s	user 0.165s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1505,"lbm_read_time_us":13449,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39956,"lbm_writes_lt_1ms":643,"mutex_wait_us":335,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":64768,"update_count":3000}
I20260812 06:20:23.074035 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=18.063937
I20260812 06:20:23.147017 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.073s	user 0.030s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26943,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.147571 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:23.159157 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.159840 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:23.365739 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.206s	user 0.137s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":14893,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36696,"lbm_writes_lt_1ms":643,"mutex_wait_us":298,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":3000}
I20260812 06:20:23.366420 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:23.433092 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.066s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.433724 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:23.446617 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.447343 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:23.633013 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.185s	user 0.139s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":13650,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33379,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:20:23.633610 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:23.696547 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.063s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23220,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.697132 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:23.708231 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.708770 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:23.888434 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.179s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1105,"lbm_read_time_us":12274,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33315,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:20:23.889027 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=10.126437
I20260812 06:20:23.922788 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.034s	user 0.005s	sys 0.027s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14734,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.923421 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:23.956920 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.033s	user 0.015s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.957564 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:24.003197 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.045s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":159,"dirs.run_wall_time_us":1101,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2180,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:24.003870 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 108082398 bytes of WAL
I20260812 06:20:24.004128 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 11 log segments from log reader
I20260812 06:20:24.004196 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000015 (ops 70-74)
I20260812 06:20:24.004251 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000016 (ops 75-78)
I20260812 06:20:24.004310 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000017 (ops 79-83)
I20260812 06:20:24.004354 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000018 (ops 84-88)
I20260812 06:20:24.004392 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000019 (ops 89-93)
I20260812 06:20:24.004432 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000020 (ops 94-98)
I20260812 06:20:24.004472 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000021 (ops 99-102)
I20260812 06:20:24.004513 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000022 (ops 103-107)
I20260812 06:20:24.004554 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000023 (ops 108-112)
I20260812 06:20:24.004593 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000024 (ops 113-116)
I20260812 06:20:24.004632 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000025 (ops 117-121)
I20260812 06:20:24.025890 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:24.026302 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=6.157687
I20260812 06:20:24.049273 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.023s	user 0.013s	sys 0.006s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9385,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:24.049778 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 12017981 bytes of WAL
I20260812 06:20:24.050001 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 1 log segments from log reader
I20260812 06:20:24.050046 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000026 (ops 122-126)
I20260812 06:20:24.052464 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:24.052802 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:24.271525 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.219s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918218,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1304,"lbm_read_time_us":14493,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34895,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:24.272558 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335): 463 bytes on disk
I20260812 06:20:24.273097 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.274009 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=18.063937
I20260812 06:20:24.341766 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.068s	user 0.034s	sys 0.029s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27528,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.342304 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:24.358294 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.358917 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:24.573103 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.214s	user 0.136s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":911,"lbm_read_time_us":13606,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35792,"lbm_writes_lt_1ms":643,"mutex_wait_us":341,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":3000}
I20260812 06:20:24.573901 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=18.063937
I20260812 06:20:24.642637 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.069s	user 0.049s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25535,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.643179 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:24.654309 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.654825 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:24.855695 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.201s	user 0.126s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":119,"lbm_read_time_us":12450,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34634,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:24.856345 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:24.899552 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.043s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.900110 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:24.914789 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.915244 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:25.098553 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.182s	user 0.131s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":722,"lbm_read_time_us":12514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30876,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:20:25.099439 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:25.154978 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.055s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26931,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.155478 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:25.172331 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.017s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.172926 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:25.338111 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.165s	user 0.113s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":11941,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28200,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:25.338804 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=14.095187
I20260812 06:20:25.394888 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.056s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20661,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.395486 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=3.181125
I20260812 06:20:25.414549 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7527,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.415010 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:25.425632 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.426106 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:25.460022 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushMRSOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.034s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1252,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1394,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:25.460755 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 112692600 bytes of WAL
I20260812 06:20:25.460981 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 11 log segments from log reader
I20260812 06:20:25.461023 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000027 (ops 127-131)
I20260812 06:20:25.461076 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000028 (ops 132-136)
I20260812 06:20:25.461119 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000029 (ops 137-141)
I20260812 06:20:25.461149 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000030 (ops 142-146)
I20260812 06:20:25.461189 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000031 (ops 147-151)
I20260812 06:20:25.461212 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000032 (ops 152-156)
I20260812 06:20:25.461251 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000033 (ops 157-161)
I20260812 06:20:25.461287 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000034 (ops 162-166)
I20260812 06:20:25.461326 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000035 (ops 167-171)
I20260812 06:20:25.461364 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000036 (ops 172-176)
I20260812 06:20:25.461426 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000037 (ops 177-181)
I20260812 06:20:25.486159 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.025s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:20:25.486605 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:25.507090 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.020s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:20:25.507561 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling LogGCOp(333d2c43672b46b1bc603d7b46eb9335): free 12017954 bytes of WAL
I20260812 06:20:25.507776 28637 log_reader.cc:385] T 333d2c43672b46b1bc603d7b46eb9335: removed 1 log segments from log reader
I20260812 06:20:25.507819 28637 log.cc:1079] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: Deleting log segment in path: /tmp/dist-test-taskifPhqu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615131889-28331-0/minicluster-data/ts-0-root/wals/333d2c43672b46b1bc603d7b46eb9335/wal-000000038 (ops 182-186)
I20260812 06:20:25.510181 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: LogGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:25.510514 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:25.523056 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.523499 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:25.753715 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.230s	user 0.181s	sys 0.048s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":328,"lbm_read_time_us":16992,"lbm_reads_lt_1ms":875,"lbm_write_time_us":43013,"lbm_writes_lt_1ms":843,"mutex_wait_us":99,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":95232,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:20:25.754472 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335): 462 bytes on disk
I20260812 06:20:25.755003 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: UndoDeltaBlockGCOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.755908 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=18.063937
I20260812 06:20:25.819336 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.063s	user 0.046s	sys 0.016s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":28546,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.819906 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=3.181125
I20260812 06:20:25.837213 28331 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.970s	user 1.852s	sys 0.162s
I20260812 06:20:25.838841 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7318,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.839289 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335): perf score=2.188937
I20260812 06:20:25.848775 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: FlushDeltaMemStoresOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3912,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":450}
I20260812 06:20:25.849258 28698 maintenance_manager.cc:419] P e774eeb284644696baae65ebaee778e4: Scheduling MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335): perf score=1.000000
I20260812 06:20:25.896733 28331 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.001s	sys 0.000s
I20260812 06:20:25.897298 28331 tablet_server.cc:179] TabletServer@127.27.170.193:0 shutting down...
I20260812 06:20:26.003010 28637 maintenance_manager.cc:643] P e774eeb284644696baae65ebaee778e4: MajorDeltaCompactionOp(333d2c43672b46b1bc603d7b46eb9335) complete. Timing: real 0.154s	user 0.115s	sys 0.038s Metrics: {"cfile_cache_hit":311,"cfile_cache_hit_bytes":12680640,"cfile_cache_miss":422,"cfile_cache_miss_bytes":20339973,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":414,"lbm_read_time_us":7866,"lbm_reads_lt_1ms":454,"lbm_write_time_us":34965,"lbm_writes_lt_1ms":743,"mutex_wait_us":97,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":84480,"update_count":3500}
I20260812 06:20:26.003826 28331 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.004107 28331 tablet_replica.cc:333] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4: stopping tablet replica
I20260812 06:20:26.004313 28331 raft_consensus.cc:2243] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.004491 28331 raft_consensus.cc:2272] T 333d2c43672b46b1bc603d7b46eb9335 P e774eeb284644696baae65ebaee778e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.009135 28331 tablet_server.cc:196] TabletServer@127.27.170.193:0 shutdown complete.
I20260812 06:20:26.063102 28331 master.cc:562] Master@127.27.170.254:39767 shutting down...
I20260812 06:20:26.066970 28331 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.067169 28331 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.067221 28331 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7936169553e040ff807715bd8198efcf: stopping tablet replica
I20260812 06:20:26.079571 28331 master.cc:584] Master@127.27.170.254:39767 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5531 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11028 ms total)

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