[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:54.905941  1414 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.97.190:43857
I20260812 06:19:54.906893  1414 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:54.907495  1414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:54.913801  1414 server_base.cc:1061] running on GCE node
W20260812 06:19:54.913772  1423 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.914004  1425 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.914110  1429 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.914638  1414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.914764  1414 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.914827  1414 hybrid_clock.cc:648] HybridClock initialized: now 1786515594914824 us; error 0 us; skew 500 ppm
I20260812 06:19:54.916560  1414 webserver.cc:533] Webserver started at http://127.1.97.190:45221/ using document root <none> and password file <none>
I20260812 06:19:54.917100  1414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.917189  1414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.917460  1414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.919107  1414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/master-0-root/instance:
uuid: "00b46adc8e444a78b8029caffb1415a6"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-zr1t"
I20260812 06:19:54.922654  1414 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:54.924676  1434 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.925787  1414 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:54.925933  1414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/master-0-root
uuid: "00b46adc8e444a78b8029caffb1415a6"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-zr1t"
I20260812 06:19:54.926041  1414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:54.934638  1414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.935227  1414 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:54.935406  1414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.942884  1414 rpc_server.cc:307] RPC server started. Bound to: 127.1.97.190:43857
I20260812 06:19:54.942885  1518 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.97.190:43857 every 8 connection(s)
I20260812 06:19:54.945034  1519 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.950217  1519 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: Bootstrap starting.
I20260812 06:19:54.952427  1519 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.953240  1519 log.cc:826] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:54.954841  1519 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: No bootstrap required, opened a new log
I20260812 06:19:54.957435  1519 raft_consensus.cc:359] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER }
I20260812 06:19:54.957677  1519 raft_consensus.cc:385] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.957732  1519 raft_consensus.cc:740] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 00b46adc8e444a78b8029caffb1415a6, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.958254  1519 consensus_queue.cc:260] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [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: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER }
I20260812 06:19:54.958385  1519 raft_consensus.cc:399] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.958425  1519 raft_consensus.cc:493] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.958513  1519 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.959285  1519 raft_consensus.cc:515] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER }
I20260812 06:19:54.959671  1519 leader_election.cc:304] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [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: 00b46adc8e444a78b8029caffb1415a6; no voters: 
I20260812 06:19:54.959955  1519 leader_election.cc:290] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.960244  1523 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.960470  1523 raft_consensus.cc:697] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 1 LEADER]: Becoming Leader. State: Replica: 00b46adc8e444a78b8029caffb1415a6, State: Running, Role: LEADER
I20260812 06:19:54.960904  1523 consensus_queue.cc:237] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [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: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER }
I20260812 06:19:54.960971  1519 sys_catalog.cc:565] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:54.963009  1525 sys_catalog.cc:455] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "00b46adc8e444a78b8029caffb1415a6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER } }
I20260812 06:19:54.963147  1525 sys_catalog.cc:458] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.963397  1526 sys_catalog.cc:455] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 00b46adc8e444a78b8029caffb1415a6. Latest consensus state: current_term: 1 leader_uuid: "00b46adc8e444a78b8029caffb1415a6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00b46adc8e444a78b8029caffb1415a6" member_type: VOTER } }
I20260812 06:19:54.963465  1414 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:54.963493  1526 sys_catalog.cc:458] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.963546  1552 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:54.965976  1552 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:54.970737  1552 catalog_manager.cc:1383] Generated new cluster ID: 4ac48a5ffb25436c86729cab9eb2756f
I20260812 06:19:54.970808  1552 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:54.987895  1552 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:54.988734  1552 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:54.995296  1552 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: Generated new TSK 0
I20260812 06:19:54.995880  1552 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.028236  1414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.031036  1563 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.031140  1569 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.031064  1561 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.031419  1414 server_base.cc:1061] running on GCE node
I20260812 06:19:55.031622  1414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.031672  1414 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:55.031687  1414 hybrid_clock.cc:648] HybridClock initialized: now 1786515595031688 us; error 0 us; skew 500 ppm
I20260812 06:19:55.032752  1414 webserver.cc:533] Webserver started at http://127.1.97.129:32855/ using document root <none> and password file <none>
I20260812 06:19:55.032938  1414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.033001  1414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.033102  1414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.033569  1414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/instance:
uuid: "6af7899ae0514cd58361bf7d78ebf13c"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-zr1t"
I20260812 06:19:55.035145  1414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:55.036170  1576 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.036454  1414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:55.036518  1414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root
uuid: "6af7899ae0514cd58361bf7d78ebf13c"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-zr1t"
I20260812 06:19:55.036605  1414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:55.050830  1414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.051335  1414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.051839  1414 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.052793  1414 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.052845  1414 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.052898  1414 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.052920  1414 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.060706  1414 rpc_server.cc:307] RPC server started. Bound to: 127.1.97.129:40239
I20260812 06:19:55.060823  1685 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.97.129:40239 every 8 connection(s)
I20260812 06:19:55.075457  1687 heartbeater.cc:344] Connected to a master server at 127.1.97.190:43857
I20260812 06:19:55.075726  1687 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.076174  1687 heartbeater.cc:507] Master 127.1.97.190:43857 requested a full tablet report, sending...
I20260812 06:19:55.077683  1461 ts_manager.cc:194] Registered new tserver with Master: 6af7899ae0514cd58361bf7d78ebf13c (127.1.97.129:40239)
I20260812 06:19:55.077930  1414 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016520887s
I20260812 06:19:55.079198  1461 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51308
I20260812 06:19:55.088641  1461 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51324:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:55.104465  1625 tablet_service.cc:1511] Processing CreateTablet for tablet 242c3d9f776b4093b056ea0993d17eb2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=66a80e1946624f63b4f293b3f48c7796]), partition=
I20260812 06:19:55.104918  1625 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 242c3d9f776b4093b056ea0993d17eb2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.107198  1708 tablet_bootstrap.cc:492] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Bootstrap starting.
I20260812 06:19:55.108223  1708 tablet_bootstrap.cc:654] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.109369  1708 tablet_bootstrap.cc:492] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: No bootstrap required, opened a new log
I20260812 06:19:55.109453  1708 ts_tablet_manager.cc:1403] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.110145  1708 raft_consensus.cc:359] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6af7899ae0514cd58361bf7d78ebf13c" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 40239 } }
I20260812 06:19:55.110239  1708 raft_consensus.cc:385] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.110263  1708 raft_consensus.cc:740] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6af7899ae0514cd58361bf7d78ebf13c, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.110407  1708 consensus_queue.cc:260] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [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: "6af7899ae0514cd58361bf7d78ebf13c" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 40239 } }
I20260812 06:19:55.110495  1708 raft_consensus.cc:399] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.110523  1708 raft_consensus.cc:493] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.110595  1708 raft_consensus.cc:3060] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.111505  1708 raft_consensus.cc:515] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6af7899ae0514cd58361bf7d78ebf13c" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 40239 } }
I20260812 06:19:55.111619  1708 leader_election.cc:304] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [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: 6af7899ae0514cd58361bf7d78ebf13c; no voters: 
I20260812 06:19:55.111860  1708 leader_election.cc:290] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.111958  1715 raft_consensus.cc:2804] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.112119  1715 raft_consensus.cc:697] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 1 LEADER]: Becoming Leader. State: Replica: 6af7899ae0514cd58361bf7d78ebf13c, State: Running, Role: LEADER
I20260812 06:19:55.112274  1708 ts_tablet_manager.cc:1434] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:55.112290  1715 consensus_queue.cc:237] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [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: "6af7899ae0514cd58361bf7d78ebf13c" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 40239 } }
I20260812 06:19:55.112643  1687 heartbeater.cc:499] Master 127.1.97.190:43857 was elected leader, sending a full tablet report...
I20260812 06:19:55.115054  1461 catalog_manager.cc:5719] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c reported cstate change: term changed from 0 to 1, leader changed from <none> to 6af7899ae0514cd58361bf7d78ebf13c (127.1.97.129). New cstate: current_term: 1 leader_uuid: "6af7899ae0514cd58361bf7d78ebf13c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6af7899ae0514cd58361bf7d78ebf13c" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 40239 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.179160  1414 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.010s	sys 0.014s
I20260812 06:19:55.311834  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2): perf score=19.054940
I20260812 06:19:55.492533  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.180s	user 0.140s	sys 0.036s Metrics: {"bytes_written":13210026,"cfile_init":1,"compiler_manager_pool.queue_time_us":172,"delete_count":0,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1000,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45155,"lbm_writes_lt_1ms":779,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":172928,"thread_start_us":109,"threads_started":1,"update_count":1610}
I20260812 06:19:55.493810  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 20743880 bytes of WAL
I20260812 06:19:55.494110  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 2 log segments from log reader
I20260812 06:19:55.494172  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000001 (ops 1-6)
I20260812 06:19:55.494225  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000002 (ops 7-11)
I20260812 06:19:55.499709  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:55.500125  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2): 16411397 bytes on disk
I20260812 06:19:55.500772  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.501263  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=4.173312
I20260812 06:19:55.527454  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.026s	user 0.010s	sys 0.014s Metrics: {"bytes_written":6112846,"delete_count":0,"lbm_write_time_us":8432,"lbm_writes_lt_1ms":152,"reinsert_count":0,"update_count":745}
I20260812 06:19:55.527946  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:55.534337  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1189877,"delete_count":0,"lbm_write_time_us":1813,"lbm_writes_lt_1ms":32,"reinsert_count":0,"update_count":145}
I20260812 06:19:55.534721  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:55.720362  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.186s	user 0.141s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774744,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":587,"lbm_read_time_us":12573,"lbm_reads_lt_1ms":561,"lbm_write_time_us":29579,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":326,"threads_started":5,"update_count":2500}
I20260812 06:19:55.720981  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=14.095187
I20260812 06:19:55.771015  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.050s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19288,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.771471  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:55.782506  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.782953  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:55.952630  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.170s	user 0.138s	sys 0.024s 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":292,"lbm_read_time_us":10852,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29653,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:55.953183  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=11.118625
I20260812 06:19:55.993462  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16635,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.994269  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.009488  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.015s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4485,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.009963  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.019431  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.019845  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:56.169713  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.150s	user 0.125s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":557,"lbm_read_time_us":10717,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30137,"lbm_writes_lt_1ms":543,"mutex_wait_us":146,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:56.170197  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:56.209043  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.039s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16861,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.209816  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.220945  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.221551  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:56.342159  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.120s	user 0.100s	sys 0.020s 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":589,"lbm_read_time_us":9474,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22549,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:56.342875  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:56.384119  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.041s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14413,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.384598  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.394470  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.395102  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:56.522836  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.128s	user 0.103s	sys 0.024s 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":932,"lbm_read_time_us":9028,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27090,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:56.523389  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:56.575675  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.052s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17315,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.576270  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.586679  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.587198  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:56.731395  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.144s	user 0.102s	sys 0.039s 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":192,"lbm_read_time_us":10580,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25284,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:56.731992  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:56.779567  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.047s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":16468,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:19:56.780046  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:56.795324  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.795900  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:56.831220  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.035s	user 0.021s	sys 0.007s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1228,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1650,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:56.831987  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 121006451 bytes of WAL
I20260812 06:19:56.832209  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 12 log segments from log reader
I20260812 06:19:56.832254  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000003 (ops 12-16)
I20260812 06:19:56.832306  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000004 (ops 17-21)
I20260812 06:19:56.832348  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000005 (ops 22-26)
I20260812 06:19:56.832412  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000006 (ops 27-30)
I20260812 06:19:56.832450  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000007 (ops 31-35)
I20260812 06:19:56.832490  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000008 (ops 36-40)
I20260812 06:19:56.832527  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000009 (ops 41-45)
I20260812 06:19:56.832566  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000010 (ops 46-50)
I20260812 06:19:56.832603  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000011 (ops 51-55)
I20260812 06:19:56.832643  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000012 (ops 56-60)
I20260812 06:19:56.832680  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000013 (ops 61-65)
I20260812 06:19:56.832717  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000014 (ops 66-70)
I20260812 06:19:56.859619  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:56.860064  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=5.165500
I20260812 06:19:56.885831  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {"bytes_written":7097423,"delete_count":0,"lbm_write_time_us":7248,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:19:56.886468  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:57.084167  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.198s	user 0.131s	sys 0.065s Metrics: {"cfile_cache_miss":606,"cfile_cache_miss_bytes":27769570,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":588,"lbm_read_time_us":12771,"lbm_reads_lt_1ms":642,"lbm_write_time_us":33540,"lbm_writes_lt_1ms":616,"mutex_wait_us":311,"peak_mem_usage":71313375,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":76,"threads_started":1,"update_count":2865}
I20260812 06:19:57.084827  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=15.087375
I20260812 06:19:57.144680  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.060s	user 0.040s	sys 0.016s Metrics: {"bytes_written":17517555,"delete_count":0,"lbm_write_time_us":22096,"lbm_writes_lt_1ms":430,"reinsert_count":0,"update_count":2135}
I20260812 06:19:57.145277  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2): 482 bytes on disk
I20260812 06:19:57.145876  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.146373  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:57.157009  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.157464  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:57.337685  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.180s	user 0.122s	sys 0.057s Metrics: {"cfile_cache_miss":559,"cfile_cache_miss_bytes":25882342,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":138,"lbm_read_time_us":13146,"lbm_reads_lt_1ms":599,"lbm_write_time_us":33316,"lbm_writes_lt_1ms":570,"mutex_wait_us":64,"peak_mem_usage":66304613,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2635}
I20260812 06:19:57.338265  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=11.118625
I20260812 06:19:57.369572  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13816,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.370098  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:57.385648  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.386119  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:57.516566  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.130s	user 0.106s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":7381,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26386,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.517220  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:57.558579  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17369,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.559023  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:57.569998  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.570709  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:57.695742  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.125s	user 0.100s	sys 0.024s 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":906,"lbm_read_time_us":7881,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25237,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2000}
I20260812 06:19:57.696439  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:57.730963  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14825,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.731446  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:57.747081  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.747632  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:57.869777  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.122s	user 0.105s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":781,"lbm_read_time_us":8535,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24809,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:57.870342  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:57.919816  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.049s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16657,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.920418  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:57.936290  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.936848  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:58.079869  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.143s	user 0.091s	sys 0.052s 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":64,"lbm_read_time_us":11604,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24212,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:58.080477  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=10.126437
I20260812 06:19:58.115445  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.035s	user 0.007s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15343,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.115991  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.137494  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.021s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.138110  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:58.174762  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.036s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1260,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1549,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:58.175607  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2): 447 bytes on disk
I20260812 06:19:58.176014  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2) 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:19:58.176529  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=3.181125
I20260812 06:19:58.196473  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.020s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.196960  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 115943182 bytes of WAL
I20260812 06:19:58.197198  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 11 log segments from log reader
I20260812 06:19:58.197266  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000015 (ops 71-75)
I20260812 06:19:58.197322  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000016 (ops 76-80)
I20260812 06:19:58.197391  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000017 (ops 81-85)
I20260812 06:19:58.197435  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000018 (ops 86-90)
I20260812 06:19:58.197472  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000019 (ops 91-95)
I20260812 06:19:58.197542  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000020 (ops 96-100)
I20260812 06:19:58.197582  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000021 (ops 101-105)
I20260812 06:19:58.197623  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000022 (ops 106-110)
I20260812 06:19:58.197664  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000023 (ops 111-115)
I20260812 06:19:58.197702  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000024 (ops 116-120)
I20260812 06:19:58.197742  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000025 (ops 121-125)
I20260812 06:19:58.222623  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:58.223037  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.243314  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.018s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5696,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:58.243919  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 12017940 bytes of WAL
I20260812 06:19:58.244180  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 1 log segments from log reader
I20260812 06:19:58.244242  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000026 (ops 126-130)
I20260812 06:19:58.247648  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:58.248035  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:58.443800  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.196s	user 0.150s	sys 0.044s Metrics: {"cfile_cache_miss":638,"cfile_cache_miss_bytes":29041430,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":295,"lbm_read_time_us":13979,"lbm_reads_lt_1ms":670,"lbm_write_time_us":34227,"lbm_writes_lt_1ms":647,"mutex_wait_us":48,"peak_mem_usage":75706612,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":78,"threads_started":1,"update_count":3020}
I20260812 06:19:58.444841  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=14.095187
I20260812 06:19:58.499478  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.054s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16245807,"delete_count":0,"lbm_write_time_us":20479,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":1980}
I20260812 06:19:58.500002  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.521682  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.522208  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.532204  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.532590  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:58.732782  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.200s	user 0.143s	sys 0.052s Metrics: {"cfile_cache_miss":629,"cfile_cache_miss_bytes":28713125,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":262,"lbm_read_time_us":13071,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34533,"lbm_writes_lt_1ms":639,"mutex_wait_us":37,"peak_mem_usage":74337948,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2980}
I20260812 06:19:58.733438  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=16.079562
I20260812 06:19:58.788712  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.055s	user 0.039s	sys 0.013s Metrics: {"bytes_written":17599599,"delete_count":0,"lbm_write_time_us":24482,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2145}
I20260812 06:19:58.789175  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.805382  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.016s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3323184,"delete_count":0,"lbm_write_time_us":3272,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:19:58.805930  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:58.816385  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3536,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.816874  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:59.010769  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.194s	user 0.144s	sys 0.046s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877188,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":221,"lbm_read_time_us":12765,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33193,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":111872,"update_count":3000}
I20260812 06:19:59.011441  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=16.079562
I20260812 06:19:59.069089  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.057s	user 0.035s	sys 0.017s Metrics: {"bytes_written":18214961,"delete_count":0,"lbm_write_time_us":25958,"lbm_writes_lt_1ms":447,"reinsert_count":0,"update_count":2220}
I20260812 06:19:59.069626  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.196750
I20260812 06:19:59.085928  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.016s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2707809,"delete_count":0,"lbm_write_time_us":2780,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:19:59.086403  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:59.095384  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3520,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.095794  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:59.288892  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.193s	user 0.104s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877175,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3665,"dirs.run_cpu_time_us":1980,"dirs.run_wall_time_us":14882,"lbm_read_time_us":12440,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33028,"lbm_writes_lt_1ms":643,"mutex_wait_us":354,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:59.289553  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=15.087375
I20260812 06:19:59.337018  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.047s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":20637,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:59.337730  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:59.359555  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.022s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.360028  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:59.370662  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.371100  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:59.572185  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.201s	user 0.125s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":452,"lbm_read_time_us":13298,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35986,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:19:59.572902  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=14.095187
I20260812 06:19:59.628748  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.056s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25257,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.629285  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=3.181125
I20260812 06:19:59.648880  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.019s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4740,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:59.649322  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:59.658597  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3517,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.659004  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:59.691326  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushMRSOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1333,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1486,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:59.692070  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 116849739 bytes of WAL
I20260812 06:19:59.692281  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 12 log segments from log reader
I20260812 06:19:59.692328  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000027 (ops 131-135)
I20260812 06:19:59.692356  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000028 (ops 136-140)
I20260812 06:19:59.692416  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000029 (ops 141-144)
I20260812 06:19:59.692461  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000030 (ops 145-149)
I20260812 06:19:59.692508  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000031 (ops 150-154)
I20260812 06:19:59.692548  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000032 (ops 155-158)
I20260812 06:19:59.692587  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000033 (ops 159-163)
I20260812 06:19:59.692629  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000034 (ops 164-168)
I20260812 06:19:59.692668  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000035 (ops 169-173)
I20260812 06:19:59.692706  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000036 (ops 174-178)
I20260812 06:19:59.692744  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000037 (ops 179-182)
I20260812 06:19:59.692780  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000038 (ops 183-187)
I20260812 06:19:59.719762  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:59.720188  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=3.181125
I20260812 06:19:59.740123  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6993,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:59.740599  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling LogGCOp(242c3d9f776b4093b056ea0993d17eb2): free 12018004 bytes of WAL
I20260812 06:19:59.740835  1582 log_reader.cc:385] T 242c3d9f776b4093b056ea0993d17eb2: removed 1 log segments from log reader
I20260812 06:19:59.740896  1582 log.cc:1079] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/242c3d9f776b4093b056ea0993d17eb2/wal-000000039 (ops 188-192)
I20260812 06:19:59.744140  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: LogGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:59.744503  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2): 483 bytes on disk
I20260812 06:19:59.744963  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: UndoDeltaBlockGCOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.745481  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=2.188937
I20260812 06:19:59.756880  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.757501  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2): perf score=1.000000
I20260812 06:19:59.956609  1414 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.777s	user 1.725s	sys 0.135s
I20260812 06:20:00.002204  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: MajorDeltaCompactionOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.244s	user 0.159s	sys 0.085s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082256,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":18269,"lbm_reads_lt_1ms":871,"lbm_write_time_us":48205,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":4000}
I20260812 06:20:00.002734  1688 maintenance_manager.cc:419] P 6af7899ae0514cd58361bf7d78ebf13c: Scheduling FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2): perf score=14.095187
I20260812 06:20:00.045339  1414 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.001s	sys 0.000s
I20260812 06:20:00.046028  1414 tablet_server.cc:179] TabletServer@127.1.97.129:0 shutting down...
I20260812 06:20:00.091491  1582 maintenance_manager.cc:643] P 6af7899ae0514cd58361bf7d78ebf13c: FlushDeltaMemStoresOp(242c3d9f776b4093b056ea0993d17eb2) complete. Timing: real 0.089s	user 0.013s	sys 0.022s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":16225,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.092188  1414 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.092566  1414 tablet_replica.cc:333] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c: stopping tablet replica
I20260812 06:20:00.092813  1414 raft_consensus.cc:2243] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.093060  1414 raft_consensus.cc:2272] T 242c3d9f776b4093b056ea0993d17eb2 P 6af7899ae0514cd58361bf7d78ebf13c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.107578  1414 tablet_server.cc:196] TabletServer@127.1.97.129:0 shutdown complete.
I20260812 06:20:00.111862  1414 master.cc:562] Master@127.1.97.190:43857 shutting down...
I20260812 06:20:00.115401  1414 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.115566  1414 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.115650  1414 tablet_replica.cc:333] T 00000000000000000000000000000000 P 00b46adc8e444a78b8029caffb1415a6: stopping tablet replica
I20260812 06:20:00.127744  1414 master.cc:584] Master@127.1.97.190:43857 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5312 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:00.218590  1414 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.97.190:37539
I20260812 06:20:00.219007  1414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.221033  1754 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.221091  1748 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:00.221118  1750 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:00.221274  1414 server_base.cc:1061] running on GCE node
I20260812 06:20:00.221433  1414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.221486  1414 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:00.221509  1414 hybrid_clock.cc:648] HybridClock initialized: now 1786515600221509 us; error 0 us; skew 500 ppm
I20260812 06:20:00.222380  1414 webserver.cc:533] Webserver started at http://127.1.97.190:34953/ using document root <none> and password file <none>
I20260812 06:20:00.222556  1414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.222626  1414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.222703  1414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.223093  1414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/master-0-root/instance:
uuid: "ee9e528151c84cf3a69c712bfd3e35c2"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-zr1t"
I20260812 06:20:00.224584  1414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.225618  1761 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:00.225879  1414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:00.225971  1414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/master-0-root
uuid: "ee9e528151c84cf3a69c712bfd3e35c2"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-zr1t"
I20260812 06:20:00.226064  1414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-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:00.243734  1414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.244133  1414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.248361  1414 rpc_server.cc:307] RPC server started. Bound to: 127.1.97.190:37539
I20260812 06:20:00.250157  1854 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.97.190:37539 every 8 connection(s)
I20260812 06:20:00.256095  1855 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:00.270166  1855 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2: Bootstrap starting.
I20260812 06:20:00.270917  1855 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.271872  1855 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2: No bootstrap required, opened a new log
I20260812 06:20:00.272223  1855 raft_consensus.cc:359] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER }
I20260812 06:20:00.272305  1855 raft_consensus.cc:385] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.272326  1855 raft_consensus.cc:740] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ee9e528151c84cf3a69c712bfd3e35c2, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.272482  1855 consensus_queue.cc:260] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [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: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER }
I20260812 06:20:00.272575  1855 raft_consensus.cc:399] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.272620  1855 raft_consensus.cc:493] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.272655  1855 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.273313  1855 raft_consensus.cc:515] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER }
I20260812 06:20:00.273424  1855 leader_election.cc:304] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [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: ee9e528151c84cf3a69c712bfd3e35c2; no voters: 
I20260812 06:20:00.273587  1855 leader_election.cc:290] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.273707  1858 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.273943  1858 raft_consensus.cc:697] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 1 LEADER]: Becoming Leader. State: Replica: ee9e528151c84cf3a69c712bfd3e35c2, State: Running, Role: LEADER
I20260812 06:20:00.274106  1858 consensus_queue.cc:237] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [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: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER }
I20260812 06:20:00.274112  1855 sys_catalog.cc:565] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.274587  1861 sys_catalog.cc:455] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ee9e528151c84cf3a69c712bfd3e35c2. Latest consensus state: current_term: 1 leader_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER } }
I20260812 06:20:00.274679  1861 sys_catalog.cc:458] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.274570  1859 sys_catalog.cc:455] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee9e528151c84cf3a69c712bfd3e35c2" member_type: VOTER } }
I20260812 06:20:00.274812  1859 sys_catalog.cc:458] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.275321  1864 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.276315  1864 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.276523  1414 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.278090  1864 catalog_manager.cc:1383] Generated new cluster ID: 50b21d7e3ee84c5faadb1818a8346637
I20260812 06:20:00.278148  1864 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.285115  1864 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.285722  1864 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.303526  1864 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2: Generated new TSK 0
I20260812 06:20:00.303726  1864 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.308858  1414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.310778  1889 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:00.310797  1892 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:00.310935  1414 server_base.cc:1061] running on GCE node
W20260812 06:20:00.311080  1888 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:00.311255  1414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.311299  1414 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:00.311314  1414 hybrid_clock.cc:648] HybridClock initialized: now 1786515600311314 us; error 0 us; skew 500 ppm
I20260812 06:20:00.312249  1414 webserver.cc:533] Webserver started at http://127.1.97.129:39751/ using document root <none> and password file <none>
I20260812 06:20:00.312455  1414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.312522  1414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.312600  1414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.312990  1414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/instance:
uuid: "888596eaa8ec4c93926062e95338699d"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-zr1t"
I20260812 06:20:00.314491  1414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:00.315368  1898 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:00.315616  1414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.315707  1414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root
uuid: "888596eaa8ec4c93926062e95338699d"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-zr1t"
I20260812 06:20:00.315790  1414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-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:00.341241  1414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.341738  1414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.342092  1414 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.342600  1414 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.342664  1414 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.342723  1414 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.342772  1414 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.347030  1414 rpc_server.cc:307] RPC server started. Bound to: 127.1.97.129:37805
I20260812 06:20:00.347077  2007 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.97.129:37805 every 8 connection(s)
I20260812 06:20:00.357165  2009 heartbeater.cc:344] Connected to a master server at 127.1.97.190:37539
I20260812 06:20:00.357276  2009 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.357486  2009 heartbeater.cc:507] Master 127.1.97.190:37539 requested a full tablet report, sending...
I20260812 06:20:00.358139  1795 ts_manager.cc:194] Registered new tserver with Master: 888596eaa8ec4c93926062e95338699d (127.1.97.129:37805)
I20260812 06:20:00.358515  1414 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011020202s
I20260812 06:20:00.358943  1795 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45420
I20260812 06:20:00.365373  1795 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45432:
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:00.373726  1954 tablet_service.cc:1511] Processing CreateTablet for tablet 9da679c43a4b49eeb3c4b5364ba8e96f (DEFAULT_TABLE table=heavy-update-compaction-test [id=b4c6df506a0642d5aa5f7d9c10c4ade1]), partition=
I20260812 06:20:00.373965  1954 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9da679c43a4b49eeb3c4b5364ba8e96f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.375917  2026 tablet_bootstrap.cc:492] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Bootstrap starting.
I20260812 06:20:00.376765  2026 tablet_bootstrap.cc:654] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.377806  2026 tablet_bootstrap.cc:492] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: No bootstrap required, opened a new log
I20260812 06:20:00.377878  2026 ts_tablet_manager.cc:1403] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:00.378225  2026 raft_consensus.cc:359] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "888596eaa8ec4c93926062e95338699d" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 37805 } }
I20260812 06:20:00.378306  2026 raft_consensus.cc:385] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.378328  2026 raft_consensus.cc:740] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 888596eaa8ec4c93926062e95338699d, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.378468  2026 consensus_queue.cc:260] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [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: "888596eaa8ec4c93926062e95338699d" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 37805 } }
I20260812 06:20:00.378556  2026 raft_consensus.cc:399] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.378582  2026 raft_consensus.cc:493] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.378640  2026 raft_consensus.cc:3060] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.379364  2026 raft_consensus.cc:515] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "888596eaa8ec4c93926062e95338699d" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 37805 } }
I20260812 06:20:00.379519  2026 leader_election.cc:304] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [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: 888596eaa8ec4c93926062e95338699d; no voters: 
I20260812 06:20:00.379666  2026 leader_election.cc:290] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.379794  2031 raft_consensus.cc:2804] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.380007  2026 ts_tablet_manager.cc:1434] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:00.380023  2009 heartbeater.cc:499] Master 127.1.97.190:37539 was elected leader, sending a full tablet report...
I20260812 06:20:00.380075  2031 raft_consensus.cc:697] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 1 LEADER]: Becoming Leader. State: Replica: 888596eaa8ec4c93926062e95338699d, State: Running, Role: LEADER
I20260812 06:20:00.380244  2031 consensus_queue.cc:237] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [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: "888596eaa8ec4c93926062e95338699d" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 37805 } }
I20260812 06:20:00.381726  1795 catalog_manager.cc:5719] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d reported cstate change: term changed from 0 to 1, leader changed from <none> to 888596eaa8ec4c93926062e95338699d (127.1.97.129). New cstate: current_term: 1 leader_uuid: "888596eaa8ec4c93926062e95338699d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "888596eaa8ec4c93926062e95338699d" member_type: VOTER last_known_addr { host: "127.1.97.129" port: 37805 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.441102  1414 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.012s	sys 0.010s
I20260812 06:20:00.597940  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=19.054940
I20260812 06:20:00.748104  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.150s	user 0.103s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":833,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38966,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:20:00.749013  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): free 20743880 bytes of WAL
I20260812 06:20:00.749266  1908 log_reader.cc:385] T 9da679c43a4b49eeb3c4b5364ba8e96f: removed 2 log segments from log reader
I20260812 06:20:00.749357  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000001 (ops 1-6)
I20260812 06:20:00.749415  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000002 (ops 7-11)
I20260812 06:20:00.754052  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:00.754544  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:00.776255  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.776680  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:00.786036  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3501,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.786432  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:00.963095  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.176s	user 0.132s	sys 0.034s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405549,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":834,"lbm_read_time_us":11771,"lbm_reads_lt_1ms":563,"lbm_write_time_us":29700,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":347,"threads_started":5,"update_count":2450}
I20260812 06:20:00.963815  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:01.018211  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.054s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21565,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.018692  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.034549  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.035318  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:01.175907  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.140s	user 0.116s	sys 0.021s 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":225,"lbm_read_time_us":10836,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27429,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.176587  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): 16821649 bytes on disk
I20260812 06:20:01.177109  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.177616  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=11.118625
I20260812 06:20:01.205651  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.028s	user 0.007s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12465,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.206128  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.237809  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.031s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.238669  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.249264  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.249684  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:01.413847  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.164s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1020,"lbm_read_time_us":11230,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32188,"lbm_writes_lt_1ms":543,"mutex_wait_us":232,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:20:01.414418  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:01.462477  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.048s	user 0.015s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22312,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.463016  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.478699  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.479189  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:01.644630  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.165s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":9940,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33443,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.645613  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=13.103000
I20260812 06:20:01.689671  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.044s	user 0.030s	sys 0.013s Metrics: {"bytes_written":14563816,"delete_count":0,"lbm_write_time_us":19487,"lbm_writes_lt_1ms":358,"reinsert_count":0,"update_count":1775}
I20260812 06:20:01.690299  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.196750
I20260812 06:20:01.710417  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.020s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2256533,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":58,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":275}
I20260812 06:20:01.710830  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.720438  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.009s	user 0.007s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3830,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.720821  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:01.886221  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.165s	user 0.105s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":146,"lbm_read_time_us":12604,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26874,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34048,"update_count":2500}
I20260812 06:20:01.886780  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:01.945744  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.059s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27939,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.946293  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:01.962821  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6509,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.963344  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:01.989984  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.026s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1268,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1776,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:01.990545  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): free 124257248 bytes of WAL
I20260812 06:20:01.990759  1908 log_reader.cc:385] T 9da679c43a4b49eeb3c4b5364ba8e96f: removed 12 log segments from log reader
I20260812 06:20:01.990804  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000003 (ops 12-16)
I20260812 06:20:01.990832  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000004 (ops 17-21)
I20260812 06:20:01.990902  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000005 (ops 22-26)
I20260812 06:20:01.990954  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000006 (ops 27-31)
I20260812 06:20:01.990993  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000007 (ops 32-36)
I20260812 06:20:01.991053  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000008 (ops 37-41)
I20260812 06:20:01.991087  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000009 (ops 42-46)
I20260812 06:20:01.991123  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000010 (ops 47-51)
I20260812 06:20:01.991160  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000011 (ops 52-56)
I20260812 06:20:01.991199  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000012 (ops 57-61)
I20260812 06:20:01.991235  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000013 (ops 62-66)
I20260812 06:20:01.991273  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000014 (ops 67-70)
I20260812 06:20:02.020807  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:02.021379  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): 462 bytes on disk
I20260812 06:20:02.021838  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.022342  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=3.181125
I20260812 06:20:02.036262  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:20:02.036695  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.196750
I20260812 06:20:02.048484  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":4344,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:20:02.049077  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:02.264966  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.216s	user 0.167s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1208,"lbm_read_time_us":17105,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37909,"lbm_writes_lt_1ms":743,"mutex_wait_us":837,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10112,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:20:02.265556  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=18.063937
I20260812 06:20:02.334894  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.069s	user 0.039s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":33118,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.335364  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:02.357134  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.357616  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:02.367723  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.368141  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:02.550887  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.183s	user 0.120s	sys 0.062s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020630,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":525,"lbm_read_time_us":14399,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37831,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3500}
I20260812 06:20:02.555037  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=15.087375
I20260812 06:20:02.609221  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.054s	user 0.021s	sys 0.025s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22293,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:02.609890  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:02.621800  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.622263  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:02.635816  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5199,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.636282  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:02.800717  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.164s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":803,"lbm_read_time_us":12911,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35027,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":3000}
I20260812 06:20:02.801368  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:02.852526  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.051s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.853042  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:02.865079  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.865669  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:03.023478  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.158s	user 0.125s	sys 0.028s 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":1105,"lbm_read_time_us":10696,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29586,"lbm_writes_lt_1ms":543,"mutex_wait_us":366,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:20:03.024096  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:03.079092  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.055s	user 0.045s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22900,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.079588  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:03.224644  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.145s	user 0.089s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":666,"lbm_read_time_us":11221,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22205,"lbm_writes_lt_1ms":443,"mutex_wait_us":109,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:20:03.225253  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:03.277315  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.052s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20693,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.277885  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:03.288363  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.288861  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:03.329501  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.040s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1104,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2183,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:03.330189  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): free 112692374 bytes of WAL
I20260812 06:20:03.330415  1908 log_reader.cc:385] T 9da679c43a4b49eeb3c4b5364ba8e96f: removed 11 log segments from log reader
I20260812 06:20:03.330457  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000015 (ops 71-75)
I20260812 06:20:03.330511  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000016 (ops 76-80)
I20260812 06:20:03.330555  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000017 (ops 81-85)
I20260812 06:20:03.330595  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000018 (ops 86-90)
I20260812 06:20:03.330633  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000019 (ops 91-95)
I20260812 06:20:03.330673  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000020 (ops 96-100)
I20260812 06:20:03.330713  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000021 (ops 101-105)
I20260812 06:20:03.330754  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000022 (ops 106-110)
I20260812 06:20:03.330794  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000023 (ops 111-115)
I20260812 06:20:03.330833  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000024 (ops 116-120)
I20260812 06:20:03.330874  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000025 (ops 121-125)
I20260812 06:20:03.356624  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:03.357046  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): 462 bytes on disk
I20260812 06:20:03.357566  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.358096  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:03.380674  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.022s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.381211  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:03.392046  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.392478  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:03.640820  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.248s	user 0.163s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2881,"lbm_read_time_us":16613,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41055,"lbm_writes_lt_1ms":743,"mutex_wait_us":2157,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:20:03.641402  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=18.063937
I20260812 06:20:03.706377  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.065s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27282,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.706810  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:03.718096  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.718694  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:03.920403  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.202s	user 0.133s	sys 0.068s 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":836,"lbm_read_time_us":14713,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33561,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":3000}
I20260812 06:20:03.921175  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:03.968842  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16491950,"delete_count":0,"lbm_write_time_us":20866,"lbm_writes_lt_1ms":405,"reinsert_count":0,"update_count":2010}
I20260812 06:20:03.969316  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:03.995971  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:03.996383  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:04.006551  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.006947  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:04.221706  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.215s	user 0.137s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2583,"lbm_read_time_us":14657,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33428,"lbm_writes_lt_1ms":643,"mutex_wait_us":1879,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3000}
I20260812 06:20:04.222506  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=16.079562
I20260812 06:20:04.277005  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.054s	user 0.032s	sys 0.012s Metrics: {"bytes_written":17968823,"delete_count":0,"lbm_write_time_us":21548,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:20:04.277617  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.196750
I20260812 06:20:04.287948  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.010s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":2936,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:04.288385  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:04.301223  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5135,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.301702  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:04.520136  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.218s	user 0.130s	sys 0.088s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918182,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":210,"lbm_read_time_us":16538,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36963,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":3000}
I20260812 06:20:04.520823  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:04.586275  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.065s	user 0.022s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24583,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.586818  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:04.598381  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.598892  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:04.771998  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.172s	user 0.143s	sys 0.029s 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":1458,"lbm_read_time_us":12458,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29942,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:20:04.773195  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=14.095187
I20260812 06:20:04.817975  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.045s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19970,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.818548  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=2.188937
I20260812 06:20:04.835107  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.835736  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:04.861884  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushMRSOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.026s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1238,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:04.862550  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): free 128414666 bytes of WAL
I20260812 06:20:04.862771  1908 log_reader.cc:385] T 9da679c43a4b49eeb3c4b5364ba8e96f: removed 13 log segments from log reader
I20260812 06:20:04.862816  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000026 (ops 126-130)
I20260812 06:20:04.862845  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000027 (ops 131-134)
I20260812 06:20:04.862905  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000028 (ops 135-139)
I20260812 06:20:04.862946  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000029 (ops 140-144)
I20260812 06:20:04.862987  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000030 (ops 145-148)
I20260812 06:20:04.863040  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000031 (ops 149-153)
I20260812 06:20:04.863082  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000032 (ops 154-158)
I20260812 06:20:04.863125  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000033 (ops 159-163)
I20260812 06:20:04.863166  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000034 (ops 164-168)
I20260812 06:20:04.863207  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000035 (ops 169-172)
I20260812 06:20:04.863246  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000036 (ops 173-177)
I20260812 06:20:04.863286  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000037 (ops 178-182)
I20260812 06:20:04.863325  1908 log.cc:1079] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: Deleting log segment in path: /tmp/dist-test-taskaQUrWN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594895380-1414-0/minicluster-data/ts-0-root/wals/9da679c43a4b49eeb3c4b5364ba8e96f/wal-000000038 (ops 183-186)
I20260812 06:20:04.890836  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: LogGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:04.891325  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=5.165500
I20260812 06:20:04.909744  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.018s	user 0.006s	sys 0.012s Metrics: {"bytes_written":7220498,"delete_count":0,"lbm_write_time_us":7843,"lbm_writes_lt_1ms":179,"reinsert_count":0,"update_count":880}
I20260812 06:20:04.910272  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f): 473 bytes on disk
I20260812 06:20:04.910784  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: UndoDeltaBlockGCOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.911442  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=1.000000
I20260812 06:20:05.123714  1414 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.683s	user 1.765s	sys 0.132s
I20260812 06:20:05.129745  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: MajorDeltaCompactionOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.218s	user 0.141s	sys 0.076s Metrics: {"cfile_cache_miss":709,"cfile_cache_miss_bytes":32036050,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1043,"lbm_read_time_us":18139,"lbm_reads_lt_1ms":745,"lbm_write_time_us":38865,"lbm_writes_lt_1ms":719,"mutex_wait_us":933,"peak_mem_usage":84903436,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":78,"threads_started":1,"update_count":3380}
I20260812 06:20:05.130839  2010 maintenance_manager.cc:419] P 888596eaa8ec4c93926062e95338699d: Scheduling FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f): perf score=19.056125
I20260812 06:20:05.154747  1414 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.003s	sys 0.000s
I20260812 06:20:05.155326  1414 tablet_server.cc:179] TabletServer@127.1.97.129:0 shutting down...
I20260812 06:20:05.182670  1908 maintenance_manager.cc:643] P 888596eaa8ec4c93926062e95338699d: FlushDeltaMemStoresOp(9da679c43a4b49eeb3c4b5364ba8e96f) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":21496900,"delete_count":0,"lbm_write_time_us":23707,"lbm_writes_lt_1ms":527,"reinsert_count":0,"update_count":2620}
I20260812 06:20:05.183203  1414 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.183425  1414 tablet_replica.cc:333] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d: stopping tablet replica
I20260812 06:20:05.183596  1414 raft_consensus.cc:2243] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.183784  1414 raft_consensus.cc:2272] T 9da679c43a4b49eeb3c4b5364ba8e96f P 888596eaa8ec4c93926062e95338699d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.197139  1414 tablet_server.cc:196] TabletServer@127.1.97.129:0 shutdown complete.
I20260812 06:20:05.199890  1414 master.cc:562] Master@127.1.97.190:37539 shutting down...
I20260812 06:20:05.203136  1414 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.203261  1414 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.203308  1414 tablet_replica.cc:333] T 00000000000000000000000000000000 P ee9e528151c84cf3a69c712bfd3e35c2: stopping tablet replica
I20260812 06:20:05.215461  1414 master.cc:584] Master@127.1.97.190:37539 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5090 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10403 ms total)

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