[==========] 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:01.077451  9929 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.178.126:46159
I20260812 06:20:01.078395  9929 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:01.078951  9929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:01.084558  9940 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:01.084695  9944 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:01.084725  9929 server_base.cc:1061] running on GCE node
W20260812 06:20:01.084883  9939 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:01.085330  9929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:01.085423  9929 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:01.085464  9929 hybrid_clock.cc:648] HybridClock initialized: now 1786515601085462 us; error 0 us; skew 500 ppm
I20260812 06:20:01.087006  9929 webserver.cc:533] Webserver started at http://127.9.178.126:39335/ using document root <none> and password file <none>
I20260812 06:20:01.087481  9929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:01.087551  9929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:01.087767  9929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:01.089241  9929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/master-0-root/instance:
uuid: "a8d7b96d49ba4900bde351f6e6c79102"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-tc2s"
I20260812 06:20:01.092427  9929 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.005s
I20260812 06:20:01.094290  9956 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:01.095176  9929 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:01.095276  9929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/master-0-root
uuid: "a8d7b96d49ba4900bde351f6e6c79102"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-tc2s"
I20260812 06:20:01.095353  9929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-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:01.103181  9929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:01.103659  9929 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:01.103787  9929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:01.110433  9929 rpc_server.cc:307] RPC server started. Bound to: 127.9.178.126:46159
I20260812 06:20:01.110435 10039 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.178.126:46159 every 8 connection(s)
I20260812 06:20:01.112419 10040 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:01.117478 10040 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: Bootstrap starting.
I20260812 06:20:01.119670 10040 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:01.120491 10040 log.cc:826] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:01.121973 10040 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: No bootstrap required, opened a new log
I20260812 06:20:01.124529 10040 raft_consensus.cc:359] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER }
I20260812 06:20:01.124675 10040 raft_consensus.cc:385] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:01.124712 10040 raft_consensus.cc:740] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a8d7b96d49ba4900bde351f6e6c79102, State: Initialized, Role: FOLLOWER
I20260812 06:20:01.125204 10040 consensus_queue.cc:260] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [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: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER }
I20260812 06:20:01.125329 10040 raft_consensus.cc:399] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:01.125372 10040 raft_consensus.cc:493] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:01.125452 10040 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:01.126157 10040 raft_consensus.cc:515] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER }
I20260812 06:20:01.126526 10040 leader_election.cc:304] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [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: a8d7b96d49ba4900bde351f6e6c79102; no voters: 
I20260812 06:20:01.126761 10040 leader_election.cc:290] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:01.126881 10049 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:01.127085 10049 raft_consensus.cc:697] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 1 LEADER]: Becoming Leader. State: Replica: a8d7b96d49ba4900bde351f6e6c79102, State: Running, Role: LEADER
I20260812 06:20:01.127489 10049 consensus_queue.cc:237] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [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: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER }
I20260812 06:20:01.127609 10040 sys_catalog.cc:565] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:01.129215 10051 sys_catalog.cc:455] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a8d7b96d49ba4900bde351f6e6c79102. Latest consensus state: current_term: 1 leader_uuid: "a8d7b96d49ba4900bde351f6e6c79102" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER } }
I20260812 06:20:01.129318 10051 sys_catalog.cc:458] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:01.129282 10050 sys_catalog.cc:455] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a8d7b96d49ba4900bde351f6e6c79102" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8d7b96d49ba4900bde351f6e6c79102" member_type: VOTER } }
I20260812 06:20:01.129376 10050 sys_catalog.cc:458] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:01.129712  9929 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:01.131436 10071 catalog_manager.cc:1594] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:01.131497 10071 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:01.131567 10068 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:01.132251 10068 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:01.136546 10068 catalog_manager.cc:1383] Generated new cluster ID: e5283777f90f4008b1d2d329b37be350
I20260812 06:20:01.136605 10068 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:01.145686 10068 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:01.146445 10068 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:01.153508 10068 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: Generated new TSK 0
I20260812 06:20:01.154057 10068 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:01.162135  9929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:01.164386 10077 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:01.164417 10078 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:01.164595  9929 server_base.cc:1061] running on GCE node
W20260812 06:20:01.164690 10081 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:01.164876  9929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:01.164943  9929 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:01.164965  9929 hybrid_clock.cc:648] HybridClock initialized: now 1786515601164965 us; error 0 us; skew 500 ppm
I20260812 06:20:01.165799  9929 webserver.cc:533] Webserver started at http://127.9.178.65:33905/ using document root <none> and password file <none>
I20260812 06:20:01.165988  9929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:01.166049  9929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:01.166121  9929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:01.166508  9929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/instance:
uuid: "4041c7d837a1452496ff58f8f8aefa36"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-tc2s"
I20260812 06:20:01.168213  9929 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:01.169240 10086 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:01.169498  9929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:01.169574  9929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root
uuid: "4041c7d837a1452496ff58f8f8aefa36"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-tc2s"
I20260812 06:20:01.169634  9929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-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:01.189761  9929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:01.190127  9929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:01.190510  9929 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:01.191234  9929 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:01.191282  9929 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.191323  9929 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:01.191351  9929 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.196805  9929 rpc_server.cc:307] RPC server started. Bound to: 127.9.178.65:39323
I20260812 06:20:01.196854 10184 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.178.65:39323 every 8 connection(s)
I20260812 06:20:01.208563 10188 heartbeater.cc:344] Connected to a master server at 127.9.178.126:46159
I20260812 06:20:01.208797 10188 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:01.209270 10188 heartbeater.cc:507] Master 127.9.178.126:46159 requested a full tablet report, sending...
I20260812 06:20:01.210681  9977 ts_manager.cc:194] Registered new tserver with Master: 4041c7d837a1452496ff58f8f8aefa36 (127.9.178.65:39323)
I20260812 06:20:01.210763  9929 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013395824s
I20260812 06:20:01.212110  9977 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39576
I20260812 06:20:01.219303  9977 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39584:
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:01.232061 10131 tablet_service.cc:1511] Processing CreateTablet for tablet 17dcc5c25d3945c58e1d84a2b8ce70b1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=114009b99f894dc7a32d1787cc390844]), partition=
I20260812 06:20:01.232420 10131 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 17dcc5c25d3945c58e1d84a2b8ce70b1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:01.234474 10209 tablet_bootstrap.cc:492] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Bootstrap starting.
I20260812 06:20:01.235224 10209 tablet_bootstrap.cc:654] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:01.236249 10209 tablet_bootstrap.cc:492] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: No bootstrap required, opened a new log
I20260812 06:20:01.236382 10209 ts_tablet_manager.cc:1403] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:01.236838 10209 raft_consensus.cc:359] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4041c7d837a1452496ff58f8f8aefa36" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 39323 } }
I20260812 06:20:01.236958 10209 raft_consensus.cc:385] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:01.236999 10209 raft_consensus.cc:740] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4041c7d837a1452496ff58f8f8aefa36, State: Initialized, Role: FOLLOWER
I20260812 06:20:01.237116 10209 consensus_queue.cc:260] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [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: "4041c7d837a1452496ff58f8f8aefa36" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 39323 } }
I20260812 06:20:01.237205 10209 raft_consensus.cc:399] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:01.237246 10209 raft_consensus.cc:493] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:01.237291 10209 raft_consensus.cc:3060] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:01.238215 10209 raft_consensus.cc:515] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4041c7d837a1452496ff58f8f8aefa36" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 39323 } }
I20260812 06:20:01.238361 10209 leader_election.cc:304] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [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: 4041c7d837a1452496ff58f8f8aefa36; no voters: 
I20260812 06:20:01.238543 10209 leader_election.cc:290] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:01.238662 10211 raft_consensus.cc:2804] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:01.238835 10209 ts_tablet_manager.cc:1434] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:01.238878 10211 raft_consensus.cc:697] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 1 LEADER]: Becoming Leader. State: Replica: 4041c7d837a1452496ff58f8f8aefa36, State: Running, Role: LEADER
I20260812 06:20:01.239027 10188 heartbeater.cc:499] Master 127.9.178.126:46159 was elected leader, sending a full tablet report...
I20260812 06:20:01.239029 10211 consensus_queue.cc:237] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [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: "4041c7d837a1452496ff58f8f8aefa36" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 39323 } }
I20260812 06:20:01.241488  9977 catalog_manager.cc:5719] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4041c7d837a1452496ff58f8f8aefa36 (127.9.178.65). New cstate: current_term: 1 leader_uuid: "4041c7d837a1452496ff58f8f8aefa36" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4041c7d837a1452496ff58f8f8aefa36" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 39323 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:01.305780  9929 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.027s	sys 0.000s
I20260812 06:20:01.448046 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=19.054940
I20260812 06:20:01.639457 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.191s	user 0.137s	sys 0.052s Metrics: {"bytes_written":16409904,"cfile_init":1,"compiler_manager_pool.queue_time_us":1019,"delete_count":0,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":833,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46969,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":118,"threads_started":1,"update_count":2000}
I20260812 06:20:01.640841 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): free 20743880 bytes of WAL
I20260812 06:20:01.641217 10094 log_reader.cc:385] T 17dcc5c25d3945c58e1d84a2b8ce70b1: removed 2 log segments from log reader
I20260812 06:20:01.641340 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000001 (ops 1-6)
I20260812 06:20:01.641446 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000002 (ops 7-11)
I20260812 06:20:01.646874 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:01.647220 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=3.181125
I20260812 06:20:01.667109 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.020s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6270,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:01.667637 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): 16411392 bytes on disk
I20260812 06:20:01.668206 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.668624 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:01.680800 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4816,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.681202 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:01.862713 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.181s	user 0.126s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":696,"lbm_read_time_us":12738,"lbm_reads_lt_1ms":669,"lbm_write_time_us":30126,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":276,"threads_started":5,"update_count":3000}
I20260812 06:20:01.863142 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:01.907959 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19294,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.908440 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.050474 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.142s	user 0.093s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":749,"lbm_read_time_us":10082,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23276,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:20:02.050917 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=11.118625
I20260812 06:20:02.080726 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.030s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12327,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.081328 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.094563 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.095031 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.209666 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.114s	user 0.084s	sys 0.029s 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":2021,"lbm_read_time_us":7056,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21250,"lbm_writes_lt_1ms":443,"mutex_wait_us":823,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43136,"update_count":2000}
I20260812 06:20:02.210245 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:02.245518 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.035s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.246093 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.255998 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.256855 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.377020 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.120s	user 0.104s	sys 0.016s 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":722,"lbm_read_time_us":7707,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.377466 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:02.415113 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.038s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13009,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.415644 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.430023 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.430513 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.554039 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.123s	user 0.094s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":8933,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21615,"lbm_writes_lt_1ms":443,"mutex_wait_us":249,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:02.554575 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:02.605152 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.050s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15142,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.605671 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.615782 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.616215 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.755457 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.139s	user 0.095s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":508,"lbm_read_time_us":10927,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23026,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:20:02.755911 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:02.797564 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.042s	user 0.020s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12289,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.798075 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.813050 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.813601 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:02.840629 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1125,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1397,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:02.841425 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): free 124257238 bytes of WAL
I20260812 06:20:02.841630 10094 log_reader.cc:385] T 17dcc5c25d3945c58e1d84a2b8ce70b1: removed 12 log segments from log reader
I20260812 06:20:02.841676 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000003 (ops 12-16)
I20260812 06:20:02.841706 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000004 (ops 17-21)
I20260812 06:20:02.841738 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000005 (ops 22-26)
I20260812 06:20:02.841771 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000006 (ops 27-31)
I20260812 06:20:02.841804 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000007 (ops 32-36)
I20260812 06:20:02.841837 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000008 (ops 37-41)
I20260812 06:20:02.841877 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000009 (ops 42-46)
I20260812 06:20:02.841943 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000010 (ops 47-51)
I20260812 06:20:02.841977 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000011 (ops 52-56)
I20260812 06:20:02.842010 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000012 (ops 57-61)
I20260812 06:20:02.842041 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000013 (ops 62-66)
I20260812 06:20:02.842073 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000014 (ops 67-70)
I20260812 06:20:02.864732 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:20:02.865078 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=3.181125
I20260812 06:20:02.891672 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.026s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:02.892166 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:02.906252 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5282,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.906713 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): 473 bytes on disk
I20260812 06:20:02.907219 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.907680 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.085253 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.177s	user 0.151s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":587,"lbm_read_time_us":13564,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30850,"lbm_writes_lt_1ms":643,"mutex_wait_us":271,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:20:03.085826 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=11.118625
I20260812 06:20:03.118798 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13722,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.119302 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:03.134683 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5691,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.135257 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.274497 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.139s	user 0.096s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":758,"lbm_read_time_us":7698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22128,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:20:03.275067 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:03.306703 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.031s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13513,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.307176 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:03.321821 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.322319 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.452538 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.130s	user 0.095s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":108,"lbm_read_time_us":9669,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23160,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:03.453342 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:03.495905 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.042s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15955,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.496402 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:03.511335 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.511780 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.628721 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.117s	user 0.085s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":98,"lbm_read_time_us":9541,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20709,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:20:03.629375 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:03.675343 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.046s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.675827 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:03.685559 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.685978 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.822692 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.137s	user 0.096s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":841,"lbm_read_time_us":10157,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22287,"lbm_writes_lt_1ms":443,"mutex_wait_us":258,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:03.825315 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:03.866283 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.041s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16814,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.866726 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:03.881518 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.882091 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:03.995956 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.114s	user 0.084s	sys 0.028s 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":1341,"lbm_read_time_us":8004,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21184,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:03.996531 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:04.026535 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.030s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12734,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.027118 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:04.041857 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.042438 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:04.151353 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.109s	user 0.068s	sys 0.040s 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":208,"lbm_read_time_us":7985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21626,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:20:04.151918 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:04.198436 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.046s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13689,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.198942 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:04.213590 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.214057 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:04.253085 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.039s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1205,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1469,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:04.253805 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): free 121006436 bytes of WAL
I20260812 06:20:04.254086 10094 log_reader.cc:385] T 17dcc5c25d3945c58e1d84a2b8ce70b1: removed 12 log segments from log reader
I20260812 06:20:04.254134 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000015 (ops 71-75)
I20260812 06:20:04.254163 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000016 (ops 76-80)
I20260812 06:20:04.254195 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000017 (ops 81-84)
I20260812 06:20:04.254228 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000018 (ops 85-89)
I20260812 06:20:04.254261 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000019 (ops 90-94)
I20260812 06:20:04.254292 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000020 (ops 95-99)
I20260812 06:20:04.254331 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000021 (ops 100-104)
I20260812 06:20:04.254364 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000022 (ops 105-109)
I20260812 06:20:04.254395 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000023 (ops 110-114)
I20260812 06:20:04.254427 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000024 (ops 115-119)
I20260812 06:20:04.254458 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000025 (ops 120-124)
I20260812 06:20:04.254489 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000026 (ops 125-129)
I20260812 06:20:04.274824 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.021s	user 0.004s	sys 0.016s Metrics: {}
I20260812 06:20:04.275183 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): 472 bytes on disk
I20260812 06:20:04.275573 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) 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:04.276022 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:04.295542 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.019s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.295953 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:04.305403 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.305956 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:04.484725 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.179s	user 0.106s	sys 0.073s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":151,"lbm_read_time_us":12450,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30492,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:20:04.485838 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:04.531087 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.045s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18745,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.531569 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:04.695406 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.164s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1194,"lbm_read_time_us":10044,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27480,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:04.695973 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:04.743559 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.744019 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:04.754081 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.754676 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:04.934856 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.180s	user 0.122s	sys 0.045s 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":511,"lbm_read_time_us":10956,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29018,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:04.935417 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:04.989274 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.054s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20480,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.989805 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:05.003820 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.004343 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:05.160509 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.156s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":10805,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28577,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:20:05.161065 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:05.204248 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.043s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21013,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.204847 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:05.216703 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.217187 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:05.363188 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.146s	user 0.115s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":9128,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28296,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:20:05.363709 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:05.412824 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.049s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24894,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.413393 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:05.424142 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.425287 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:05.575752 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.150s	user 0.097s	sys 0.047s 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":530,"lbm_read_time_us":8823,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30473,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:05.576282 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=14.095187
I20260812 06:20:05.625597 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.049s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21640,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.626082 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:05.635895 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.636467 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:05.662439 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushMRSOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1785,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1480,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:05.663174 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): free 124710562 bytes of WAL
I20260812 06:20:05.663404 10094 log_reader.cc:385] T 17dcc5c25d3945c58e1d84a2b8ce70b1: removed 12 log segments from log reader
I20260812 06:20:05.663453 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000027 (ops 130-134)
I20260812 06:20:05.663491 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000028 (ops 135-139)
I20260812 06:20:05.663524 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000029 (ops 140-144)
I20260812 06:20:05.663555 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000030 (ops 145-149)
I20260812 06:20:05.663586 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000031 (ops 150-154)
I20260812 06:20:05.663616 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000032 (ops 155-159)
I20260812 06:20:05.663646 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000033 (ops 160-164)
I20260812 06:20:05.663676 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000034 (ops 165-169)
I20260812 06:20:05.663705 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000035 (ops 170-174)
I20260812 06:20:05.663735 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000036 (ops 175-179)
I20260812 06:20:05.663764 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000037 (ops 180-184)
I20260812 06:20:05.663793 10094 log.cc:1079] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/17dcc5c25d3945c58e1d84a2b8ce70b1/wal-000000038 (ops 185-189)
I20260812 06:20:05.686148 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: LogGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:05.686618 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1): 482 bytes on disk
I20260812 06:20:05.687026 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: UndoDeltaBlockGCOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.687744 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=3.181125
I20260812 06:20:05.700716 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:05.701112 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=2.188937
I20260812 06:20:05.710060 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3511,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.710521 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=1.000000
I20260812 06:20:05.827157  9929 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.521s	user 1.667s	sys 0.121s
I20260812 06:20:05.881484 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: MajorDeltaCompactionOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.171s	user 0.130s	sys 0.039s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14869,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32754,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3500}
I20260812 06:20:05.882006 10191 maintenance_manager.cc:419] P 4041c7d837a1452496ff58f8f8aefa36: Scheduling FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1): perf score=10.126437
I20260812 06:20:05.903023  9929 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.003s	sys 0.000s
I20260812 06:20:05.903616  9929 tablet_server.cc:179] TabletServer@127.9.178.65:0 shutting down...
I20260812 06:20:05.931979 10094 maintenance_manager.cc:643] P 4041c7d837a1452496ff58f8f8aefa36: FlushDeltaMemStoresOp(17dcc5c25d3945c58e1d84a2b8ce70b1) complete. Timing: real 0.050s	user 0.015s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13493,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.932494  9929 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.932861  9929 tablet_replica.cc:333] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36: stopping tablet replica
I20260812 06:20:05.933091  9929 raft_consensus.cc:2243] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.933314  9929 raft_consensus.cc:2272] T 17dcc5c25d3945c58e1d84a2b8ce70b1 P 4041c7d837a1452496ff58f8f8aefa36 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.947510  9929 tablet_server.cc:196] TabletServer@127.9.178.65:0 shutdown complete.
I20260812 06:20:05.951843  9929 master.cc:562] Master@127.9.178.126:46159 shutting down...
I20260812 06:20:05.955156  9929 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.955286  9929 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.955358  9929 tablet_replica.cc:333] T 00000000000000000000000000000000 P a8d7b96d49ba4900bde351f6e6c79102: stopping tablet replica
I20260812 06:20:05.967115  9929 master.cc:584] Master@127.9.178.126:46159 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4961 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:06.039222  9929 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.178.126:34453
I20260812 06:20:06.039563  9929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.041383 10237 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:06.041388 10239 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:06.041486 10243 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:06.041608  9929 server_base.cc:1061] running on GCE node
I20260812 06:20:06.041754  9929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.041797  9929 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:06.041823  9929 hybrid_clock.cc:648] HybridClock initialized: now 1786515606041823 us; error 0 us; skew 500 ppm
I20260812 06:20:06.042611  9929 webserver.cc:533] Webserver started at http://127.9.178.126:35687/ using document root <none> and password file <none>
I20260812 06:20:06.042769  9929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.042814  9929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.042888  9929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.043243  9929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/master-0-root/instance:
uuid: "3d117d8c2b0b4093b22c341a576708f0"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-tc2s"
I20260812 06:20:06.044608  9929 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:06.045480 10257 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:06.045714  9929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.045778  9929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/master-0-root
uuid: "3d117d8c2b0b4093b22c341a576708f0"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-tc2s"
I20260812 06:20:06.045832  9929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-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:06.056910  9929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.057173  9929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.060787  9929 rpc_server.cc:307] RPC server started. Bound to: 127.9.178.126:34453
I20260812 06:20:06.074852 10345 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.178.126:34453 every 8 connection(s)
I20260812 06:20:06.075282 10346 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:06.076956 10346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0: Bootstrap starting.
I20260812 06:20:06.077663 10346 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.078589 10346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0: No bootstrap required, opened a new log
I20260812 06:20:06.078933 10346 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER }
I20260812 06:20:06.079012 10346 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.079038 10346 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3d117d8c2b0b4093b22c341a576708f0, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.079137 10346 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [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: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER }
I20260812 06:20:06.079195 10346 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.079221 10346 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.079252 10346 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.079856 10346 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER }
I20260812 06:20:06.079964 10346 leader_election.cc:304] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [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: 3d117d8c2b0b4093b22c341a576708f0; no voters: 
I20260812 06:20:06.080098 10346 leader_election.cc:290] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.080193 10353 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.080384 10353 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 1 LEADER]: Becoming Leader. State: Replica: 3d117d8c2b0b4093b22c341a576708f0, State: Running, Role: LEADER
I20260812 06:20:06.080538 10346 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.080516 10353 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [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: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER }
I20260812 06:20:06.080922 10357 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3d117d8c2b0b4093b22c341a576708f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER } }
I20260812 06:20:06.080951 10358 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3d117d8c2b0b4093b22c341a576708f0. Latest consensus state: current_term: 1 leader_uuid: "3d117d8c2b0b4093b22c341a576708f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d117d8c2b0b4093b22c341a576708f0" member_type: VOTER } }
I20260812 06:20:06.081080 10357 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.081135 10358 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.081583 10365 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.082329 10365 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.082520  9929 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.083961 10365 catalog_manager.cc:1383] Generated new cluster ID: 46b7f36ff0d544a2a65b77bd12f987a7
I20260812 06:20:06.084010 10365 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.116729 10365 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.117233 10365 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.123638 10365 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0: Generated new TSK 0
I20260812 06:20:06.123797 10365 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.146888  9929 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.148732 10388 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:06.148808 10397 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:06.148826  9929 server_base.cc:1061] running on GCE node
W20260812 06:20:06.148754 10392 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:06.149083  9929 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.149132  9929 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:06.149147  9929 hybrid_clock.cc:648] HybridClock initialized: now 1786515606149147 us; error 0 us; skew 500 ppm
I20260812 06:20:06.149960  9929 webserver.cc:533] Webserver started at http://127.9.178.65:41655/ using document root <none> and password file <none>
I20260812 06:20:06.150115  9929 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.150164  9929 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.150238  9929 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.150624  9929 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/instance:
uuid: "e8e49ae3c3f34434b7e228b22ba194b7"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-tc2s"
I20260812 06:20:06.152022  9929 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:06.152870 10405 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:06.153079  9929 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:06.153144  9929 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root
uuid: "e8e49ae3c3f34434b7e228b22ba194b7"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-tc2s"
I20260812 06:20:06.153210  9929 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-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:06.166807  9929 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.167117  9929 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.167373  9929 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.167798  9929 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.167835  9929 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.167876  9929 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.167904  9929 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.171721  9929 rpc_server.cc:307] RPC server started. Bound to: 127.9.178.65:38015
I20260812 06:20:06.171748 10512 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.178.65:38015 every 8 connection(s)
I20260812 06:20:06.175923 10513 heartbeater.cc:344] Connected to a master server at 127.9.178.126:34453
I20260812 06:20:06.176011 10513 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.176173 10513 heartbeater.cc:507] Master 127.9.178.126:34453 requested a full tablet report, sending...
I20260812 06:20:06.176750 10283 ts_manager.cc:194] Registered new tserver with Master: e8e49ae3c3f34434b7e228b22ba194b7 (127.9.178.65:38015)
I20260812 06:20:06.177428 10283 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58850
I20260812 06:20:06.177660  9929 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005568768s
I20260812 06:20:06.183882 10283 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58860:
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:06.191843 10448 tablet_service.cc:1511] Processing CreateTablet for tablet 7dffc518d01d4d25bc6479cbb4976ba4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=bc969756ec704fc4987fc762fb16613b]), partition=
I20260812 06:20:06.192068 10448 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7dffc518d01d4d25bc6479cbb4976ba4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.193851 10531 tablet_bootstrap.cc:492] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Bootstrap starting.
I20260812 06:20:06.194857 10531 tablet_bootstrap.cc:654] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.195812 10531 tablet_bootstrap.cc:492] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: No bootstrap required, opened a new log
I20260812 06:20:06.195889 10531 ts_tablet_manager.cc:1403] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:06.196265 10531 raft_consensus.cc:359] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8e49ae3c3f34434b7e228b22ba194b7" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 38015 } }
I20260812 06:20:06.196372 10531 raft_consensus.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.196409 10531 raft_consensus.cc:740] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e8e49ae3c3f34434b7e228b22ba194b7, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.196538 10531 consensus_queue.cc:260] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [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: "e8e49ae3c3f34434b7e228b22ba194b7" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 38015 } }
I20260812 06:20:06.196609 10531 raft_consensus.cc:399] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.196645 10531 raft_consensus.cc:493] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.196695 10531 raft_consensus.cc:3060] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.197540 10531 raft_consensus.cc:515] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8e49ae3c3f34434b7e228b22ba194b7" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 38015 } }
I20260812 06:20:06.197669 10531 leader_election.cc:304] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [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: e8e49ae3c3f34434b7e228b22ba194b7; no voters: 
I20260812 06:20:06.197846 10531 leader_election.cc:290] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.197997 10533 raft_consensus.cc:2804] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.198180 10531 ts_tablet_manager.cc:1434] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:06.198226 10513 heartbeater.cc:499] Master 127.9.178.126:34453 was elected leader, sending a full tablet report...
I20260812 06:20:06.198213 10533 raft_consensus.cc:697] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 1 LEADER]: Becoming Leader. State: Replica: e8e49ae3c3f34434b7e228b22ba194b7, State: Running, Role: LEADER
I20260812 06:20:06.198415 10533 consensus_queue.cc:237] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [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: "e8e49ae3c3f34434b7e228b22ba194b7" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 38015 } }
I20260812 06:20:06.199612 10283 catalog_manager.cc:5719] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 reported cstate change: term changed from 0 to 1, leader changed from <none> to e8e49ae3c3f34434b7e228b22ba194b7 (127.9.178.65). New cstate: current_term: 1 leader_uuid: "e8e49ae3c3f34434b7e228b22ba194b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8e49ae3c3f34434b7e228b22ba194b7" member_type: VOTER last_known_addr { host: "127.9.178.65" port: 38015 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.253959  9929 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.004s
I20260812 06:20:06.422556 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=23.023690
I20260812 06:20:06.564801 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.142s	user 0.106s	sys 0.033s Metrics: {"bytes_written":12676709,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":803,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37097,"lbm_writes_lt_1ms":866,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":6016,"update_count":1545}
I20260812 06:20:06.565588 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4): free 20743880 bytes of WAL
I20260812 06:20:06.565976 10412 log_reader.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4: removed 2 log segments from log reader
I20260812 06:20:06.566118 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000001 (ops 1-6)
I20260812 06:20:06.566249 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000002 (ops 7-11)
I20260812 06:20:06.571381 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:06.571715 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4): 20513815 bytes on disk
I20260812 06:20:06.572095 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.572611 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:06.593693 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.021s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4020613,"delete_count":0,"lbm_write_time_us":4863,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:06.594080 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:06.603008 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3815483,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:06.603339 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:06.774797 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.171s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815800,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":464,"lbm_read_time_us":10875,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27785,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":286,"threads_started":5,"update_count":2500}
I20260812 06:20:06.775399 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:06.820369 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.045s	user 0.023s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":16415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.820816 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:06.835839 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.836387 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:06.982002 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.145s	user 0.099s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":455,"lbm_read_time_us":11282,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25169,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2500}
I20260812 06:20:06.983280 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=11.118625
I20260812 06:20:07.032387 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.049s	user 0.027s	sys 0.009s Metrics: {"bytes_written":13456166,"delete_count":0,"lbm_write_time_us":16262,"lbm_writes_lt_1ms":331,"reinsert_count":0,"update_count":1640}
I20260812 06:20:07.032917 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=5.165500
I20260812 06:20:07.049788 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":7056405,"delete_count":0,"lbm_write_time_us":6983,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:20:07.050256 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:07.186028 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.136s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2968,"lbm_read_time_us":8459,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25068,"lbm_writes_lt_1ms":543,"mutex_wait_us":2023,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:07.186503 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:07.234100 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.047s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":20921,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.234581 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:07.244722 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.245329 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:07.402043 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.157s	user 0.117s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":9490,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26784,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:20:07.402618 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:07.461741 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.059s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23066,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.462229 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:07.477041 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.477638 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:07.648294 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.170s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":351,"lbm_read_time_us":13227,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26418,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:07.648904 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:07.709565 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.061s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.710111 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:07.721079 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.721570 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:07.749058 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.027s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1226,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1409,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:07.749707 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4): free 121006443 bytes of WAL
I20260812 06:20:07.749958 10412 log_reader.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4: removed 12 log segments from log reader
I20260812 06:20:07.750017 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000003 (ops 12-16)
I20260812 06:20:07.750061 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000004 (ops 17-21)
I20260812 06:20:07.750090 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000005 (ops 22-26)
I20260812 06:20:07.750123 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000006 (ops 27-30)
I20260812 06:20:07.750154 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000007 (ops 31-35)
I20260812 06:20:07.750181 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000008 (ops 36-40)
I20260812 06:20:07.750211 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000009 (ops 41-45)
I20260812 06:20:07.750239 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000010 (ops 46-50)
I20260812 06:20:07.750272 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000011 (ops 51-55)
I20260812 06:20:07.750303 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000012 (ops 56-60)
I20260812 06:20:07.750329 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000013 (ops 61-65)
I20260812 06:20:07.750357 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000014 (ops 66-70)
I20260812 06:20:07.774051 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.024s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:07.774430 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4): 471 bytes on disk
I20260812 06:20:07.774804 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.775254 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=3.181125
I20260812 06:20:07.795372 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.020s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:07.795809 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4): free 11564875 bytes of WAL
I20260812 06:20:07.796003 10412 log_reader.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4: removed 1 log segments from log reader
I20260812 06:20:07.796061 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000015 (ops 71-74)
I20260812 06:20:07.798765 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:07.799077 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:07.813957 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5607,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.814368 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:08.017410 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.203s	user 0.138s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1013,"lbm_read_time_us":15829,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35270,"lbm_writes_lt_1ms":743,"mutex_wait_us":288,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:08.017994 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=18.063937
I20260812 06:20:08.066713 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.049s	user 0.040s	sys 0.008s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":21587,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:08.067411 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:08.080456 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.080924 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:08.235461 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.154s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":128,"lbm_read_time_us":10937,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30713,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":3000}
I20260812 06:20:08.235982 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:08.281106 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.045s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19775,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.281592 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:08.296366 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.296917 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:08.438015 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.141s	user 0.103s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1303,"lbm_read_time_us":10008,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25896,"lbm_writes_lt_1ms":543,"mutex_wait_us":253,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:08.439458 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=13.103000
I20260812 06:20:08.477025 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.037s	user 0.025s	sys 0.008s Metrics: {"bytes_written":14604841,"delete_count":0,"lbm_write_time_us":16561,"lbm_writes_lt_1ms":359,"reinsert_count":0,"update_count":1780}
I20260812 06:20:08.477525 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.196750
I20260812 06:20:08.485599 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2215508,"delete_count":0,"lbm_write_time_us":2665,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:20:08.486053 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:08.628032 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.142s	user 0.103s	sys 0.036s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123472,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":691,"lbm_read_time_us":11130,"lbm_reads_lt_1ms":474,"lbm_write_time_us":21137,"lbm_writes_lt_1ms":453,"mutex_wait_us":245,"peak_mem_usage":51099678,"reinsert_count":0,"update_count":2050}
I20260812 06:20:08.628575 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:08.674996 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.046s	user 0.038s	sys 0.003s Metrics: {"bytes_written":15999663,"delete_count":0,"lbm_write_time_us":18186,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:20:08.675537 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:08.698992 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.023s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.699523 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:08.873862 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.174s	user 0.111s	sys 0.057s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24405445,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":12106,"lbm_reads_lt_1ms":562,"lbm_write_time_us":27511,"lbm_writes_lt_1ms":533,"mutex_wait_us":250,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2450}
I20260812 06:20:08.874370 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:08.915256 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.041s	user 0.016s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17875,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:08.915786 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:08.931056 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.931527 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:09.104027 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.172s	user 0.113s	sys 0.049s 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":531,"lbm_read_time_us":10514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27889,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:09.104511 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:09.153191 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.049s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19542,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.153757 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:09.167999 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.168516 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:09.202656 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":1036,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2124,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:09.203392 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4): free 124710332 bytes of WAL
I20260812 06:20:09.203611 10412 log_reader.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4: removed 12 log segments from log reader
I20260812 06:20:09.203651 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000016 (ops 75-79)
I20260812 06:20:09.203691 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000017 (ops 80-84)
I20260812 06:20:09.203727 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000018 (ops 85-89)
I20260812 06:20:09.203789 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000019 (ops 90-94)
I20260812 06:20:09.203826 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000020 (ops 95-99)
I20260812 06:20:09.203882 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000021 (ops 100-104)
I20260812 06:20:09.203917 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000022 (ops 105-109)
I20260812 06:20:09.203967 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000023 (ops 110-114)
I20260812 06:20:09.204002 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000024 (ops 115-119)
I20260812 06:20:09.204062 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000025 (ops 120-124)
I20260812 06:20:09.204110 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000026 (ops 125-129)
I20260812 06:20:09.204150 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000027 (ops 130-134)
I20260812 06:20:09.230857 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:09.231261 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4): 493 bytes on disk
I20260812 06:20:09.231740 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.232395 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=6.157687
I20260812 06:20:09.253557 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.021s	user 0.011s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8864,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:09.254076 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:09.487222 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.233s	user 0.149s	sys 0.083s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020628,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":476,"lbm_read_time_us":16245,"lbm_reads_lt_1ms":769,"lbm_write_time_us":37488,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:20:09.488904 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=18.063937
I20260812 06:20:09.551705 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.063s	user 0.024s	sys 0.036s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28639,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.552233 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:09.562947 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.563380 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:09.777690 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.214s	user 0.134s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":905,"lbm_read_time_us":14108,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31527,"lbm_writes_lt_1ms":643,"mutex_wait_us":285,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:20:09.778229 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=18.063937
I20260812 06:20:09.839366 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.061s	user 0.036s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25921,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.839865 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:09.855903 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.856338 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:10.045292 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.189s	user 0.145s	sys 0.044s 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":154,"lbm_read_time_us":13815,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32325,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":96512,"update_count":3000}
I20260812 06:20:10.045951 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:10.093432 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.047s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19499,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.093973 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:10.104166 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.104550 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:10.268792 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.164s	user 0.124s	sys 0.040s 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":320,"lbm_read_time_us":12310,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26243,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40448,"update_count":2500}
I20260812 06:20:10.269364 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:10.319743 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.050s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20627,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.320160 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:10.330137 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.330514 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:10.508661 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.178s	user 0.134s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":605,"lbm_read_time_us":12517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31044,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:10.509243 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=14.095187
I20260812 06:20:10.559857 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.050s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17812,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.560415 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:10.570645 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.571058 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:10.610093 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushMRSOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.039s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1167,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:10.610903 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4): free 121006692 bytes of WAL
I20260812 06:20:10.611159 10412 log_reader.cc:385] T 7dffc518d01d4d25bc6479cbb4976ba4: removed 12 log segments from log reader
I20260812 06:20:10.611210 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000028 (ops 135-139)
I20260812 06:20:10.611239 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000029 (ops 140-144)
I20260812 06:20:10.611258 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000030 (ops 145-149)
I20260812 06:20:10.611289 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000031 (ops 150-154)
I20260812 06:20:10.611320 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000032 (ops 155-159)
I20260812 06:20:10.611353 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000033 (ops 160-164)
I20260812 06:20:10.611373 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000034 (ops 165-168)
I20260812 06:20:10.611398 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000035 (ops 169-173)
I20260812 06:20:10.611431 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000036 (ops 174-178)
I20260812 06:20:10.611462 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000037 (ops 179-183)
I20260812 06:20:10.611493 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000038 (ops 184-188)
I20260812 06:20:10.611526 10412 log.cc:1079] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: Deleting log segment in path: /tmp/dist-test-taskGEcq3Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515601067364-9929-0/minicluster-data/ts-0-root/wals/7dffc518d01d4d25bc6479cbb4976ba4/wal-000000039 (ops 189-193)
I20260812 06:20:10.631811 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: LogGCOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:10.632200 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:10.656157 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.024s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.656601 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4): 461 bytes on disk
I20260812 06:20:10.657015 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: UndoDeltaBlockGCOp(7dffc518d01d4d25bc6479cbb4976ba4) 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:10.657512 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=2.188937
I20260812 06:20:10.669839 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: FlushDeltaMemStoresOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.670264 10514 maintenance_manager.cc:419] P e8e49ae3c3f34434b7e228b22ba194b7: Scheduling MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4): perf score=1.000000
I20260812 06:20:10.749432  9929 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.495s	user 1.639s	sys 0.169s
I20260812 06:20:10.835846  9929 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.001s	sys 0.000s
I20260812 06:20:10.836330  9929 tablet_server.cc:179] TabletServer@127.9.178.65:0 shutting down...
I20260812 06:20:10.865126 10412 maintenance_manager.cc:643] P e8e49ae3c3f34434b7e228b22ba194b7: MajorDeltaCompactionOp(7dffc518d01d4d25bc6479cbb4976ba4) complete. Timing: real 0.195s	user 0.103s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":577,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":770,"lbm_write_time_us":30079,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":82944,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:10.865624  9929 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:10.865842  9929 tablet_replica.cc:333] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7: stopping tablet replica
I20260812 06:20:10.865995  9929 raft_consensus.cc:2243] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.866160  9929 raft_consensus.cc:2272] T 7dffc518d01d4d25bc6479cbb4976ba4 P e8e49ae3c3f34434b7e228b22ba194b7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.880873  9929 tablet_server.cc:196] TabletServer@127.9.178.65:0 shutdown complete.
I20260812 06:20:10.921434  9929 master.cc:562] Master@127.9.178.126:34453 shutting down...
I20260812 06:20:10.924415  9929 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.924616  9929 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.924685  9929 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3d117d8c2b0b4093b22c341a576708f0: stopping tablet replica
I20260812 06:20:10.936841  9929 master.cc:584] Master@127.9.178.126:34453 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4966 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9928 ms total)

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