[==========] 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:17:13.317200  5953 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.208.126:44969
I20260812 06:17:13.318233  5953 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:17:13.318846  5953 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:13.325385  5963 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:17:13.325428  5961 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:17:13.325583  5953 server_base.cc:1061] running on GCE node
W20260812 06:17:13.325816  5967 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:17:13.326325  5953 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:13.326454  5953 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:17:13.326498  5953 hybrid_clock.cc:648] HybridClock initialized: now 1786515433326495 us; error 0 us; skew 500 ppm
I20260812 06:17:13.328233  5953 webserver.cc:533] Webserver started at http://127.5.208.126:45897/ using document root <none> and password file <none>
I20260812 06:17:13.328845  5953 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:13.328929  5953 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:13.329169  5953 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:13.330781  5953 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/master-0-root/instance:
uuid: "85f28f54bb374328847512d9da4b7f70"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-x5fp"
I20260812 06:17:13.334328  5953 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:13.336309  5976 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:17:13.337335  5953 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:13.337489  5953 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/master-0-root
uuid: "85f28f54bb374328847512d9da4b7f70"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-x5fp"
I20260812 06:17:13.337594  5953 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-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:17:13.360646  5953 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:13.361377  5953 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:17:13.361568  5953 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:13.371297  5953 rpc_server.cc:307] RPC server started. Bound to: 127.5.208.126:44969
I20260812 06:17:13.371304  6065 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.208.126:44969 every 8 connection(s)
I20260812 06:17:13.373713  6067 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:17:13.379225  6067 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: Bootstrap starting.
I20260812 06:17:13.381598  6067 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:13.382511  6067 log.cc:826] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:13.384243  6067 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: No bootstrap required, opened a new log
I20260812 06:17:13.386958  6067 raft_consensus.cc:359] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER }
I20260812 06:17:13.387153  6067 raft_consensus.cc:385] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:13.387264  6067 raft_consensus.cc:740] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 85f28f54bb374328847512d9da4b7f70, State: Initialized, Role: FOLLOWER
I20260812 06:17:13.387943  6067 consensus_queue.cc:260] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [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: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER }
I20260812 06:17:13.388127  6067 raft_consensus.cc:399] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:13.388218  6067 raft_consensus.cc:493] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:13.388351  6067 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:13.389133  6067 raft_consensus.cc:515] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER }
I20260812 06:17:13.389588  6067 leader_election.cc:304] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [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: 85f28f54bb374328847512d9da4b7f70; no voters: 
I20260812 06:17:13.389937  6067 leader_election.cc:290] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:13.390137  6072 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:13.390440  6072 raft_consensus.cc:697] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 1 LEADER]: Becoming Leader. State: Replica: 85f28f54bb374328847512d9da4b7f70, State: Running, Role: LEADER
I20260812 06:17:13.390846  6072 consensus_queue.cc:237] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [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: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER }
I20260812 06:17:13.390938  6067 sys_catalog.cc:565] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:13.393163  5953 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:13.393134  6074 sys_catalog.cc:455] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 85f28f54bb374328847512d9da4b7f70. Latest consensus state: current_term: 1 leader_uuid: "85f28f54bb374328847512d9da4b7f70" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER } }
I20260812 06:17:13.393244  6074 sys_catalog.cc:458] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:13.393165  6073 sys_catalog.cc:455] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "85f28f54bb374328847512d9da4b7f70" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85f28f54bb374328847512d9da4b7f70" member_type: VOTER } }
I20260812 06:17:13.393308  6073 sys_catalog.cc:458] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [sys.catalog]: This master's current role is: LEADER
W20260812 06:17:13.395471  6093 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:13.395565  6093 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:13.395639  6094 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:13.396399  6094 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:13.401310  6094 catalog_manager.cc:1383] Generated new cluster ID: ca561c6dcfd444c9a9231946d133d14a
I20260812 06:17:13.401396  6094 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:13.421412  6094 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:13.422341  6094 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:13.431643  6094 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: Generated new TSK 0
I20260812 06:17:13.432299  6094 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:13.458153  5953 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:13.461287  6102 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:17:13.461369  6104 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:17:13.461385  6100 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:17:13.461606  5953 server_base.cc:1061] running on GCE node
I20260812 06:17:13.461895  5953 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:13.461967  5953 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:17:13.461995  5953 hybrid_clock.cc:648] HybridClock initialized: now 1786515433461995 us; error 0 us; skew 500 ppm
I20260812 06:17:13.463075  5953 webserver.cc:533] Webserver started at http://127.5.208.65:38167/ using document root <none> and password file <none>
I20260812 06:17:13.463268  5953 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:13.463344  5953 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:13.463430  5953 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:13.463863  5953 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/instance:
uuid: "a43209ff300e46d0943ca9b8f35aefed"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-x5fp"
I20260812 06:17:13.465540  5953 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:13.466549  6114 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:17:13.466826  5953 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:13.466892  5953 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root
uuid: "a43209ff300e46d0943ca9b8f35aefed"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-x5fp"
I20260812 06:17:13.466981  5953 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-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:17:13.501943  5953 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:13.502435  5953 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:13.502974  5953 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:13.503937  5953 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:13.503995  5953 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:13.504045  5953 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:13.504107  5953 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:13.511623  5953 rpc_server.cc:307] RPC server started. Bound to: 127.5.208.65:34057
I20260812 06:17:13.511644  6220 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.208.65:34057 every 8 connection(s)
I20260812 06:17:13.525470  6221 heartbeater.cc:344] Connected to a master server at 127.5.208.126:44969
I20260812 06:17:13.525724  6221 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:13.526186  6221 heartbeater.cc:507] Master 127.5.208.126:44969 requested a full tablet report, sending...
I20260812 06:17:13.527580  6007 ts_manager.cc:194] Registered new tserver with Master: a43209ff300e46d0943ca9b8f35aefed (127.5.208.65:34057)
I20260812 06:17:13.528162  5953 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015807317s
I20260812 06:17:13.528887  6007 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33128
I20260812 06:17:13.539502  6007 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33138:
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:17:13.554226  6164 tablet_service.cc:1511] Processing CreateTablet for tablet a5a941fbe68a4bada968778df6fb1cf0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3941dda7a592435bbda506812a758998]), partition=
I20260812 06:17:13.554741  6164 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a5a941fbe68a4bada968778df6fb1cf0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:13.557716  6246 tablet_bootstrap.cc:492] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Bootstrap starting.
I20260812 06:17:13.558542  6246 tablet_bootstrap.cc:654] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:13.560110  6246 tablet_bootstrap.cc:492] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: No bootstrap required, opened a new log
I20260812 06:17:13.560237  6246 ts_tablet_manager.cc:1403] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:13.560926  6246 raft_consensus.cc:359] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a43209ff300e46d0943ca9b8f35aefed" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 34057 } }
I20260812 06:17:13.561053  6246 raft_consensus.cc:385] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:13.561131  6246 raft_consensus.cc:740] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a43209ff300e46d0943ca9b8f35aefed, State: Initialized, Role: FOLLOWER
I20260812 06:17:13.561331  6246 consensus_queue.cc:260] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [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: "a43209ff300e46d0943ca9b8f35aefed" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 34057 } }
I20260812 06:17:13.561424  6246 raft_consensus.cc:399] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:13.561472  6246 raft_consensus.cc:493] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:13.561534  6246 raft_consensus.cc:3060] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:13.562252  6246 raft_consensus.cc:515] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a43209ff300e46d0943ca9b8f35aefed" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 34057 } }
I20260812 06:17:13.562397  6246 leader_election.cc:304] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [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: a43209ff300e46d0943ca9b8f35aefed; no voters: 
I20260812 06:17:13.562613  6246 leader_election.cc:290] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:13.562708  6248 raft_consensus.cc:2804] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:13.562883  6248 raft_consensus.cc:697] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 1 LEADER]: Becoming Leader. State: Replica: a43209ff300e46d0943ca9b8f35aefed, State: Running, Role: LEADER
I20260812 06:17:13.562996  6246 ts_tablet_manager.cc:1434] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:13.563082  6248 consensus_queue.cc:237] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [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: "a43209ff300e46d0943ca9b8f35aefed" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 34057 } }
I20260812 06:17:13.563306  6221 heartbeater.cc:499] Master 127.5.208.126:44969 was elected leader, sending a full tablet report...
I20260812 06:17:13.566140  6007 catalog_manager.cc:5719] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed reported cstate change: term changed from 0 to 1, leader changed from <none> to a43209ff300e46d0943ca9b8f35aefed (127.5.208.65). New cstate: current_term: 1 leader_uuid: "a43209ff300e46d0943ca9b8f35aefed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a43209ff300e46d0943ca9b8f35aefed" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 34057 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:13.631322  5953 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.024s	sys 0.004s
I20260812 06:17:13.762804  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=19.054940
I20260812 06:17:13.951212  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.188s	user 0.158s	sys 0.016s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":824,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":849,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43902,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":158,"threads_started":1,"update_count":1500}
I20260812 06:17:13.952497  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling LogGCOp(a5a941fbe68a4bada968778df6fb1cf0): free 20743880 bytes of WAL
I20260812 06:17:13.952862  6126 log_reader.cc:385] T a5a941fbe68a4bada968778df6fb1cf0: removed 2 log segments from log reader
I20260812 06:17:13.952932  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000001 (ops 1-6)
I20260812 06:17:13.952986  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000002 (ops 7-11)
I20260812 06:17:13.958643  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: LogGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:13.959152  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0): 16411395 bytes on disk
I20260812 06:17:13.959856  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.960359  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:13.981650  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.021s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.982300  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:14.134557  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.152s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":686,"lbm_read_time_us":9398,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25143,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":320,"threads_started":5,"update_count":2000}
I20260812 06:17:14.135318  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:14.170286  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.035s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15129,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:17:14.170861  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:14.186399  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.186908  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:14.303889  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.117s	user 0.089s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":9164,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22235,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:17:14.304526  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:14.343678  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.039s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.344190  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:14.357570  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.358067  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:14.492861  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.135s	user 0.116s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":9414,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26251,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:14.493345  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=11.118625
I20260812 06:17:14.537361  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.044s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17359,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:14.537873  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:14.552498  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3890,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.553119  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:14.562543  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.563105  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:14.747888  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.185s	user 0.127s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":635,"lbm_read_time_us":11987,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32209,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:17:14.748515  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:14.809789  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.061s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18815,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.810302  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:14.821511  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.821959  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:15.000198  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.178s	user 0.130s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":12941,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29726,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:15.000933  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=11.118625
I20260812 06:17:15.042138  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17757,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:15.042972  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:15.065814  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.023s	user 0.012s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5100,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.066373  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:15.211058  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.144s	user 0.086s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":409,"lbm_read_time_us":10272,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23544,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:15.211841  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:15.255422  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.043s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16169,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.256011  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:15.271319  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.271839  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:15.305838  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1675,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:15.306663  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling LogGCOp(a5a941fbe68a4bada968778df6fb1cf0): free 120553376 bytes of WAL
I20260812 06:17:15.306900  6126 log_reader.cc:385] T a5a941fbe68a4bada968778df6fb1cf0: removed 12 log segments from log reader
I20260812 06:17:15.306946  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000003 (ops 12-16)
I20260812 06:17:15.306977  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000004 (ops 17-20)
I20260812 06:17:15.307034  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000005 (ops 21-25)
I20260812 06:17:15.307073  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000006 (ops 26-30)
I20260812 06:17:15.307114  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000007 (ops 31-35)
I20260812 06:17:15.307179  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000008 (ops 36-40)
I20260812 06:17:15.307207  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000009 (ops 41-45)
I20260812 06:17:15.307261  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000010 (ops 46-50)
I20260812 06:17:15.307297  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000011 (ops 51-55)
I20260812 06:17:15.307335  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000012 (ops 56-60)
I20260812 06:17:15.307377  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000013 (ops 61-64)
I20260812 06:17:15.307415  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000014 (ops 65-69)
I20260812 06:17:15.333750  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: LogGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:15.334168  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0): 472 bytes on disk
I20260812 06:17:15.334712  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.335322  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=3.181125
I20260812 06:17:15.347347  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4553933,"delete_count":0,"lbm_write_time_us":4698,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:15.347837  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:15.357239  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3605,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:15.357859  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:15.549649  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.192s	user 0.132s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":490,"lbm_read_time_us":12837,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33877,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":102,"threads_started":1,"update_count":3000}
I20260812 06:17:15.550287  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:15.599666  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.049s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.600278  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:15.616369  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.617005  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:15.809012  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.192s	user 0.137s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":12962,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30040,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:15.809721  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:15.858932  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20298,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.859491  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:15.874056  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5824,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.874511  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.020835  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.146s	user 0.119s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30738,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:17:16.021476  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:16.056200  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.035s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14732,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.056660  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:16.074376  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.074959  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.205824  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.131s	user 0.102s	sys 0.028s 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":298,"lbm_read_time_us":10044,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25484,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:16.206383  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:16.247004  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.040s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16251,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.247519  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.359290  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.112s	user 0.091s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":135,"lbm_read_time_us":6796,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21951,"lbm_writes_lt_1ms":343,"mutex_wait_us":41,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.360019  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:16.401929  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.042s	user 0.032s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.402441  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:16.413169  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.413952  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.545109  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.131s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":745,"lbm_read_time_us":9891,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25227,"lbm_writes_lt_1ms":443,"mutex_wait_us":345,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:16.545925  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:16.584342  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.038s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.584957  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:16.597138  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.597596  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.715121  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.117s	user 0.097s	sys 0.020s 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":926,"lbm_read_time_us":7775,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22623,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:16.716049  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=10.126437
I20260812 06:17:16.756116  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.040s	user 0.024s	sys 0.010s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16550,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.756642  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:16.768445  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.769047  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:16.799185  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1412,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:16.800024  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling LogGCOp(a5a941fbe68a4bada968778df6fb1cf0): free 129320524 bytes of WAL
I20260812 06:17:16.800258  6126 log_reader.cc:385] T a5a941fbe68a4bada968778df6fb1cf0: removed 13 log segments from log reader
I20260812 06:17:16.800303  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000015 (ops 70-74)
I20260812 06:17:16.800334  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000016 (ops 75-79)
I20260812 06:17:16.800396  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000017 (ops 80-84)
I20260812 06:17:16.800437  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000018 (ops 85-89)
I20260812 06:17:16.800475  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000019 (ops 90-94)
I20260812 06:17:16.800513  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000020 (ops 95-99)
I20260812 06:17:16.800551  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000021 (ops 100-104)
I20260812 06:17:16.800585  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000022 (ops 105-108)
I20260812 06:17:16.800621  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000023 (ops 109-113)
I20260812 06:17:16.800657  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000024 (ops 114-118)
I20260812 06:17:16.800696  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000025 (ops 119-122)
I20260812 06:17:16.800805  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000026 (ops 123-127)
I20260812 06:17:16.800858  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000027 (ops 128-132)
I20260812 06:17:16.832374  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: LogGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.032s	user 0.006s	sys 0.023s Metrics: {}
I20260812 06:17:16.832970  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0): 482 bytes on disk
I20260812 06:17:16.833654  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.834349  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=4.173312
I20260812 06:17:16.853314  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":6030800,"delete_count":0,"lbm_write_time_us":7785,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:17:16.853927  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.196750
I20260812 06:17:16.864439  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":3269,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:17:16.864981  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:17.035650  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.170s	user 0.141s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877293,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1016,"lbm_read_time_us":12133,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34080,"lbm_writes_lt_1ms":643,"mutex_wait_us":349,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:17.036358  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:17.089116  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.053s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23613,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.089689  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:17.100957  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.101438  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:17.257485  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.156s	user 0.120s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":12172,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30325,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:17:17.258083  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=11.118625
I20260812 06:17:17.297354  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.039s	user 0.023s	sys 0.016s Metrics: {"bytes_written":13251053,"delete_count":0,"lbm_write_time_us":17305,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:17:17.297948  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.196750
I20260812 06:17:17.317430  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.019s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4984,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:17:17.318037  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:17.471292  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.153s	user 0.087s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672261,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":9165,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25961,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:17:17.472091  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:17.522262  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.050s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19855,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.522794  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:17.543219  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.543912  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:17.728657  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.185s	user 0.108s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":12347,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29943,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:17:17.729980  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:17.783417  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.053s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20921,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.784006  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:17.795048  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.795775  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:17.986120  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.190s	user 0.124s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":10850,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31272,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:17:17.986743  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:18.044942  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.058s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21461,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.045497  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:18.057092  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.057598  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:18.206120  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.148s	user 0.118s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":9289,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30198,"lbm_writes_lt_1ms":543,"mutex_wait_us":95,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:17:18.206856  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=14.095187
I20260812 06:17:18.258509  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.051s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:18.259058  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=2.188937
I20260812 06:17:18.270660  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.271145  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:18.302371  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushMRSOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1579,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1540,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:18.303159  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling LogGCOp(a5a941fbe68a4bada968778df6fb1cf0): free 132118545 bytes of WAL
I20260812 06:17:18.303414  6126 log_reader.cc:385] T a5a941fbe68a4bada968778df6fb1cf0: removed 13 log segments from log reader
I20260812 06:17:18.303484  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000028 (ops 133-137)
I20260812 06:17:18.303534  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000029 (ops 138-142)
I20260812 06:17:18.303591  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000030 (ops 143-147)
I20260812 06:17:18.303634  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000031 (ops 148-152)
I20260812 06:17:18.303673  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000032 (ops 153-156)
I20260812 06:17:18.303746  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000033 (ops 157-161)
I20260812 06:17:18.303787  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000034 (ops 162-166)
I20260812 06:17:18.303828  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000035 (ops 167-170)
I20260812 06:17:18.303867  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000036 (ops 171-175)
I20260812 06:17:18.303906  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000037 (ops 176-180)
I20260812 06:17:18.303946  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000038 (ops 181-185)
I20260812 06:17:18.303984  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000039 (ops 186-190)
I20260812 06:17:18.304023  6126 log.cc:1079] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/a5a941fbe68a4bada968778df6fb1cf0/wal-000000040 (ops 191-194)
I20260812 06:17:18.333765  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: LogGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:18.334257  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=4.173312
I20260812 06:17:18.349985  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":6153870,"delete_count":0,"lbm_write_time_us":6251,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:17:18.350500  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:18.370220  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: FlushDeltaMemStoresOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.020s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2051402,"delete_count":0,"lbm_write_time_us":3121,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:17:18.370854  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0): 483 bytes on disk
I20260812 06:17:18.371374  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: UndoDeltaBlockGCOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.371990  6223 maintenance_manager.cc:419] P a43209ff300e46d0943ca9b8f35aefed: Scheduling MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0): perf score=1.000000
I20260812 06:17:18.475272  5953 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.844s	user 1.842s	sys 0.099s
I20260812 06:17:18.587039  5953 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.002s	sys 0.000s
I20260812 06:17:18.587769  5953 tablet_server.cc:179] TabletServer@127.5.208.65:0 shutting down...
I20260812 06:17:18.613983  6126 maintenance_manager.cc:643] P a43209ff300e46d0943ca9b8f35aefed: MajorDeltaCompactionOp(a5a941fbe68a4bada968778df6fb1cf0) complete. Timing: real 0.242s	user 0.151s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979698,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":460,"lbm_read_time_us":17333,"lbm_reads_lt_1ms":762,"lbm_write_time_us":39065,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20096,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:17:18.615332  5953 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:18.615839  5953 tablet_replica.cc:333] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed: stopping tablet replica
I20260812 06:17:18.616133  5953 raft_consensus.cc:2243] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:18.616403  5953 raft_consensus.cc:2272] T a5a941fbe68a4bada968778df6fb1cf0 P a43209ff300e46d0943ca9b8f35aefed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:18.633991  5953 tablet_server.cc:196] TabletServer@127.5.208.65:0 shutdown complete.
I20260812 06:17:18.677567  5953 master.cc:562] Master@127.5.208.126:44969 shutting down...
I20260812 06:17:18.682116  5953 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:18.682353  5953 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:18.682467  5953 tablet_replica.cc:333] T 00000000000000000000000000000000 P 85f28f54bb374328847512d9da4b7f70: stopping tablet replica
I20260812 06:17:18.695345  5953 master.cc:584] Master@127.5.208.126:44969 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5467 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:18.799731  5953 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.208.126:38857
I20260812 06:17:18.800280  5953 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:18.802840  6281 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:17:18.802944  6279 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:17:18.803046  6276 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:17:18.802920  5953 server_base.cc:1061] running on GCE node
I20260812 06:17:18.803289  5953 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:18.803337  5953 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:17:18.803377  5953 hybrid_clock.cc:648] HybridClock initialized: now 1786515438803377 us; error 0 us; skew 500 ppm
I20260812 06:17:18.804279  5953 webserver.cc:533] Webserver started at http://127.5.208.126:44805/ using document root <none> and password file <none>
I20260812 06:17:18.804435  5953 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:18.804482  5953 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:18.804541  5953 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:18.805027  5953 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/master-0-root/instance:
uuid: "6c3bbc769a9847cfa56d238392c3d56f"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-x5fp"
I20260812 06:17:18.806635  5953 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:18.807541  6291 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:17:18.807776  5953 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:18.807850  5953 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/master-0-root
uuid: "6c3bbc769a9847cfa56d238392c3d56f"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-x5fp"
I20260812 06:17:18.807912  5953 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-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:17:18.819850  5953 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:18.820232  5953 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:18.825160  5953 rpc_server.cc:307] RPC server started. Bound to: 127.5.208.126:38857
I20260812 06:17:18.830214  6373 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.208.126:38857 every 8 connection(s)
I20260812 06:17:18.831704  6374 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:17:18.833738  6374 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f: Bootstrap starting.
I20260812 06:17:18.834519  6374 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:18.835558  6374 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f: No bootstrap required, opened a new log
I20260812 06:17:18.835935  6374 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER }
I20260812 06:17:18.836023  6374 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:18.836047  6374 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6c3bbc769a9847cfa56d238392c3d56f, State: Initialized, Role: FOLLOWER
I20260812 06:17:18.836205  6374 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [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: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER }
I20260812 06:17:18.836309  6374 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:18.836338  6374 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:18.836380  6374 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:18.837141  6374 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER }
I20260812 06:17:18.837272  6374 leader_election.cc:304] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [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: 6c3bbc769a9847cfa56d238392c3d56f; no voters: 
I20260812 06:17:18.837450  6374 leader_election.cc:290] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:18.837589  6378 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:18.837863  6378 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 1 LEADER]: Becoming Leader. State: Replica: 6c3bbc769a9847cfa56d238392c3d56f, State: Running, Role: LEADER
I20260812 06:17:18.838007  6378 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [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: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER }
I20260812 06:17:18.838078  6374 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:18.838500  6380 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6c3bbc769a9847cfa56d238392c3d56f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER } }
I20260812 06:17:18.838548  6385 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6c3bbc769a9847cfa56d238392c3d56f. Latest consensus state: current_term: 1 leader_uuid: "6c3bbc769a9847cfa56d238392c3d56f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c3bbc769a9847cfa56d238392c3d56f" member_type: VOTER } }
I20260812 06:17:18.838670  6380 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:18.838691  6385 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:18.839265  6388 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:18.840328  6388 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:18.840590  5953 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:18.842356  6388 catalog_manager.cc:1383] Generated new cluster ID: f32b9913de9346fda2ff1beb9264891d
I20260812 06:17:18.842422  6388 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:18.849323  6388 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:18.849957  6388 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:18.876457  6388 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f: Generated new TSK 0
I20260812 06:17:18.876704  6388 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:18.905447  5953 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:18.907699  6416 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:17:18.907822  6414 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:17:18.907824  6419 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:17:18.908450  5953 server_base.cc:1061] running on GCE node
I20260812 06:17:18.908641  5953 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:18.908684  5953 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:17:18.908703  5953 hybrid_clock.cc:648] HybridClock initialized: now 1786515438908703 us; error 0 us; skew 500 ppm
I20260812 06:17:18.909752  5953 webserver.cc:533] Webserver started at http://127.5.208.65:46069/ using document root <none> and password file <none>
I20260812 06:17:18.909969  5953 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:18.910049  5953 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:18.910148  5953 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:18.910604  5953 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/instance:
uuid: "a8c90524614e4e2381748866846a17bb"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-x5fp"
I20260812 06:17:18.912269  5953 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:18.913492  6427 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:17:18.913810  5953 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:18.913918  5953 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root
uuid: "a8c90524614e4e2381748866846a17bb"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-x5fp"
I20260812 06:17:18.913977  5953 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-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:17:18.929344  5953 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:18.929720  5953 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:18.930006  5953 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:18.930531  5953 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:18.930572  5953 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:18.930642  5953 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:18.930688  5953 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:18.935374  5953 rpc_server.cc:307] RPC server started. Bound to: 127.5.208.65:46099
I20260812 06:17:18.935410  6539 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.208.65:46099 every 8 connection(s)
I20260812 06:17:18.946906  6540 heartbeater.cc:344] Connected to a master server at 127.5.208.126:38857
I20260812 06:17:18.947063  6540 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:18.947402  6540 heartbeater.cc:507] Master 127.5.208.126:38857 requested a full tablet report, sending...
I20260812 06:17:18.948220  6321 ts_manager.cc:194] Registered new tserver with Master: a8c90524614e4e2381748866846a17bb (127.5.208.65:46099)
I20260812 06:17:18.948424  5953 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012329516s
I20260812 06:17:18.949322  6321 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51158
I20260812 06:17:18.956542  6321 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51160:
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:17:18.965463  6479 tablet_service.cc:1511] Processing CreateTablet for tablet 5392e10da56d4ef8ae4811b210a94725 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ed0a490cd21f4b848d88517fc3bd6c97]), partition=
I20260812 06:17:18.965737  6479 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5392e10da56d4ef8ae4811b210a94725. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:18.967962  6557 tablet_bootstrap.cc:492] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Bootstrap starting.
I20260812 06:17:18.968904  6557 tablet_bootstrap.cc:654] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:18.969960  6557 tablet_bootstrap.cc:492] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: No bootstrap required, opened a new log
I20260812 06:17:18.970036  6557 ts_tablet_manager.cc:1403] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:18.970501  6557 raft_consensus.cc:359] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8c90524614e4e2381748866846a17bb" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 46099 } }
I20260812 06:17:18.970633  6557 raft_consensus.cc:385] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:18.970669  6557 raft_consensus.cc:740] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a8c90524614e4e2381748866846a17bb, State: Initialized, Role: FOLLOWER
I20260812 06:17:18.970813  6557 consensus_queue.cc:260] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [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: "a8c90524614e4e2381748866846a17bb" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 46099 } }
I20260812 06:17:18.970919  6557 raft_consensus.cc:399] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:18.970971  6557 raft_consensus.cc:493] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:18.971025  6557 raft_consensus.cc:3060] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:18.971762  6557 raft_consensus.cc:515] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8c90524614e4e2381748866846a17bb" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 46099 } }
I20260812 06:17:18.971932  6557 leader_election.cc:304] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [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: a8c90524614e4e2381748866846a17bb; no voters: 
I20260812 06:17:18.972158  6557 leader_election.cc:290] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:18.972296  6559 raft_consensus.cc:2804] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:18.972577  6540 heartbeater.cc:499] Master 127.5.208.126:38857 was elected leader, sending a full tablet report...
I20260812 06:17:18.972540  6559 raft_consensus.cc:697] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 1 LEADER]: Becoming Leader. State: Replica: a8c90524614e4e2381748866846a17bb, State: Running, Role: LEADER
I20260812 06:17:18.972548  6557 ts_tablet_manager.cc:1434] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:18.972759  6559 consensus_queue.cc:237] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [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: "a8c90524614e4e2381748866846a17bb" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 46099 } }
I20260812 06:17:18.974287  6321 catalog_manager.cc:5719] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb reported cstate change: term changed from 0 to 1, leader changed from <none> to a8c90524614e4e2381748866846a17bb (127.5.208.65). New cstate: current_term: 1 leader_uuid: "a8c90524614e4e2381748866846a17bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8c90524614e4e2381748866846a17bb" member_type: VOTER last_known_addr { host: "127.5.208.65" port: 46099 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:19.034121  5953 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:17:19.187439  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushMRSOp(5392e10da56d4ef8ae4811b210a94725): perf score=19.054940
I20260812 06:17:19.347393  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushMRSOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.160s	user 0.129s	sys 0.027s Metrics: {"bytes_written":12553636,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":869,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40755,"lbm_writes_lt_1ms":763,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":7936,"update_count":1530}
I20260812 06:17:19.348043  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling LogGCOp(5392e10da56d4ef8ae4811b210a94725): free 20743831 bytes of WAL
I20260812 06:17:19.348273  6436 log_reader.cc:385] T 5392e10da56d4ef8ae4811b210a94725: removed 2 log segments from log reader
I20260812 06:17:19.348336  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000001 (ops 1-6)
I20260812 06:17:19.348380  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000002 (ops 7-11)
I20260812 06:17:19.353852  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: LogGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:19.354198  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=3.181125
I20260812 06:17:19.373495  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.019s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4266762,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:17:19.374063  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:19.388682  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.014s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.389339  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:19.577695  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.188s	user 0.139s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":521,"lbm_read_time_us":13489,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30088,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":348,"threads_started":5,"update_count":2500}
I20260812 06:17:19.578359  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:19.625036  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.046s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20176,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.625610  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:19.642135  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.642771  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725): 16411395 bytes on disk
I20260812 06:17:19.643429  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.644057  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:19.813181  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.169s	user 0.117s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":11661,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28325,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:17:19.813840  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:19.876972  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.063s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.877539  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:19.889204  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.889664  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:20.075042  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.185s	user 0.121s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":131,"lbm_read_time_us":12016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32503,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":95744,"update_count":2500}
I20260812 06:17:20.075716  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:20.136449  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.061s	user 0.029s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.137115  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:20.154417  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.155001  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:20.345851  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.191s	user 0.104s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":14562,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28656,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:17:20.346436  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:20.396390  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.050s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21583,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.396989  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:20.418692  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.022s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.419261  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:20.609107  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.190s	user 0.141s	sys 0.047s 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":283,"lbm_read_time_us":12713,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31623,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:20.609766  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:20.666252  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.056s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20654,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.666730  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:20.679392  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.680054  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushMRSOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:20.718184  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushMRSOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":286,"dirs.run_wall_time_us":1453,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2005,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:20.718839  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling LogGCOp(5392e10da56d4ef8ae4811b210a94725): free 124257296 bytes of WAL
I20260812 06:17:20.719084  6436 log_reader.cc:385] T 5392e10da56d4ef8ae4811b210a94725: removed 12 log segments from log reader
I20260812 06:17:20.719132  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000003 (ops 12-16)
I20260812 06:17:20.719161  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000004 (ops 17-21)
I20260812 06:17:20.719224  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000005 (ops 22-26)
I20260812 06:17:20.719292  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000006 (ops 27-31)
I20260812 06:17:20.719353  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000007 (ops 32-36)
I20260812 06:17:20.719391  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000008 (ops 37-41)
I20260812 06:17:20.719432  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000009 (ops 42-46)
I20260812 06:17:20.719470  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000010 (ops 47-51)
I20260812 06:17:20.719507  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000011 (ops 52-56)
I20260812 06:17:20.719547  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000012 (ops 57-60)
I20260812 06:17:20.719594  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000013 (ops 61-65)
I20260812 06:17:20.719653  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000014 (ops 66-70)
I20260812 06:17:20.747648  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: LogGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.029s	user 0.003s	sys 0.022s Metrics: {}
I20260812 06:17:20.748046  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725): 472 bytes on disk
I20260812 06:17:20.748490  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.749006  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=3.181125
I20260812 06:17:20.764300  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4618,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.764835  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:20.775674  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.776392  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:21.024953  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.248s	user 0.153s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":552,"lbm_read_time_us":17536,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40762,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16512,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:17:21.025645  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=18.063937
I20260812 06:17:21.092285  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.066s	user 0.041s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29475,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:21.092919  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:21.108651  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.109153  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:21.322198  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.213s	user 0.113s	sys 0.087s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1246,"lbm_read_time_us":12801,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34851,"lbm_writes_lt_1ms":643,"mutex_wait_us":335,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":63872,"update_count":3000}
I20260812 06:17:21.322891  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=18.063937
I20260812 06:17:21.394579  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.071s	user 0.045s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28423,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:21.395094  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:21.406092  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.406737  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:21.610111  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.203s	user 0.127s	sys 0.074s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":821,"lbm_read_time_us":13391,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36611,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3000}
I20260812 06:17:21.610992  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=16.079562
I20260812 06:17:21.670295  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.059s	user 0.023s	sys 0.029s Metrics: {"bytes_written":18502129,"delete_count":0,"lbm_write_time_us":24181,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":453,"reinsert_count":0,"update_count":2255}
I20260812 06:17:21.670812  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=4.173312
I20260812 06:17:21.689251  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.018s	user 0.003s	sys 0.015s Metrics: {"bytes_written":6112856,"delete_count":0,"lbm_write_time_us":7166,"lbm_writes_lt_1ms":152,"reinsert_count":0,"update_count":745}
I20260812 06:17:21.689736  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:21.908851  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.219s	user 0.140s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":13061,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36965,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":3000}
I20260812 06:17:21.909678  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=18.063937
I20260812 06:17:21.982704  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.073s	user 0.030s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26433,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:21.983299  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:21.994733  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.995333  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:22.201941  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.206s	user 0.131s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":405,"lbm_read_time_us":13114,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35465,"lbm_writes_lt_1ms":643,"mutex_wait_us":80,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:17:22.202627  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=16.079562
I20260812 06:17:22.259002  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.056s	user 0.022s	sys 0.028s Metrics: {"bytes_written":18091890,"delete_count":0,"lbm_write_time_us":23683,"lbm_writes_lt_1ms":444,"reinsert_count":0,"update_count":2205}
I20260812 06:17:22.259469  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.196750
I20260812 06:17:22.270056  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.010s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2830884,"delete_count":0,"lbm_write_time_us":2771,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:22.270567  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:22.280288  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:22.280817  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushMRSOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:22.319908  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushMRSOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.039s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2481,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:22.320658  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling LogGCOp(5392e10da56d4ef8ae4811b210a94725): free 133024405 bytes of WAL
I20260812 06:17:22.320955  6436 log_reader.cc:385] T 5392e10da56d4ef8ae4811b210a94725: removed 13 log segments from log reader
I20260812 06:17:22.321024  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000015 (ops 71-75)
I20260812 06:17:22.321069  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000016 (ops 76-80)
I20260812 06:17:22.321105  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000017 (ops 81-85)
I20260812 06:17:22.321131  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000018 (ops 86-90)
I20260812 06:17:22.321164  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000019 (ops 91-94)
I20260812 06:17:22.321201  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000020 (ops 95-99)
I20260812 06:17:22.321239  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000021 (ops 100-104)
I20260812 06:17:22.321274  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000022 (ops 105-109)
I20260812 06:17:22.321307  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000023 (ops 110-114)
I20260812 06:17:22.321341  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000024 (ops 115-119)
I20260812 06:17:22.321373  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000025 (ops 120-124)
I20260812 06:17:22.321412  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000026 (ops 125-129)
I20260812 06:17:22.321448  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000027 (ops 130-134)
I20260812 06:17:22.356272  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: LogGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.035s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:22.356813  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725): 492 bytes on disk
I20260812 06:17:22.357244  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:22.357736  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=3.181125
I20260812 06:17:22.369781  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4584,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:22.370230  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:22.380820  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:22.381374  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:22.621877  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.240s	user 0.170s	sys 0.070s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082231,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":144,"lbm_read_time_us":18513,"lbm_reads_lt_1ms":875,"lbm_write_time_us":42467,"lbm_writes_lt_1ms":843,"mutex_wait_us":27,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:17:22.622761  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=19.056125
I20260812 06:17:22.683168  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.060s	user 0.030s	sys 0.021s Metrics: {"bytes_written":20922554,"delete_count":0,"lbm_write_time_us":23933,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:17:22.683633  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:22.697119  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.697558  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:22.707242  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:22.708007  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:22.913697  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.205s	user 0.165s	sys 0.039s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979618,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":949,"lbm_read_time_us":15979,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41633,"lbm_writes_lt_1ms":743,"mutex_wait_us":362,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":3500}
I20260812 06:17:22.914176  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:22.958480  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.044s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20372,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.959050  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:22.972142  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.972855  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:23.148053  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.175s	user 0.114s	sys 0.061s 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":437,"lbm_read_time_us":11232,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34788,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":59520,"update_count":2500}
I20260812 06:17:23.148854  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:23.199043  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.050s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.199635  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:23.363226  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.163s	user 0.081s	sys 0.071s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":272,"lbm_read_time_us":8952,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26893,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":124928,"update_count":2000}
I20260812 06:17:23.363958  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:23.431917  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.068s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22112,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.432672  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:23.467099  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.034s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:17:23.467725  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:23.478806  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.479307  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:23.692902  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.213s	user 0.134s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":473,"lbm_read_time_us":15358,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36756,"lbm_writes_lt_1ms":643,"mutex_wait_us":98,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":3000}
I20260812 06:17:23.693574  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=14.095187
I20260812 06:17:23.762029  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.068s	user 0.035s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25110,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.762609  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:23.784355  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.021s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.785043  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushMRSOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:23.826110  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushMRSOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1475,"drs_written":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:23.826979  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725): 472 bytes on disk
I20260812 06:17:23.827373  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: UndoDeltaBlockGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:23.827870  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=3.181125
I20260812 06:17:23.840248  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:23.840834  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling LogGCOp(5392e10da56d4ef8ae4811b210a94725): free 121006640 bytes of WAL
I20260812 06:17:23.841053  6436 log_reader.cc:385] T 5392e10da56d4ef8ae4811b210a94725: removed 12 log segments from log reader
I20260812 06:17:23.841097  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000028 (ops 135-139)
I20260812 06:17:23.841126  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000029 (ops 140-144)
I20260812 06:17:23.841183  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000030 (ops 145-149)
I20260812 06:17:23.841228  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000031 (ops 150-154)
I20260812 06:17:23.841269  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000032 (ops 155-159)
I20260812 06:17:23.841305  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000033 (ops 160-164)
I20260812 06:17:23.841344  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000034 (ops 165-169)
I20260812 06:17:23.841387  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000035 (ops 170-174)
I20260812 06:17:23.841426  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000036 (ops 175-178)
I20260812 06:17:23.841465  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000037 (ops 179-183)
I20260812 06:17:23.841504  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000038 (ops 184-188)
I20260812 06:17:23.841543  6436 log.cc:1079] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: Deleting log segment in path: /tmp/dist-test-taskX6zP3q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433306677-5953-0/minicluster-data/ts-0-root/wals/5392e10da56d4ef8ae4811b210a94725/wal-000000039 (ops 189-193)
I20260812 06:17:23.868856  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: LogGCOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:23.871145  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:23.884815  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.885360  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725): perf score=2.188937
I20260812 06:17:23.899494  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: FlushDeltaMemStoresOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5263,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:23.900055  6541 maintenance_manager.cc:419] P a8c90524614e4e2381748866846a17bb: Scheduling MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725): perf score=1.000000
I20260812 06:17:24.002251  5953 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.968s	user 1.855s	sys 0.180s
I20260812 06:17:24.106325  5953 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.001s	sys 0.000s
I20260812 06:17:24.106865  5953 tablet_server.cc:179] TabletServer@127.5.208.65:0 shutting down...
I20260812 06:17:24.151643  6436 maintenance_manager.cc:643] P a8c90524614e4e2381748866846a17bb: MajorDeltaCompactionOp(5392e10da56d4ef8ae4811b210a94725) complete. Timing: real 0.251s	user 0.162s	sys 0.089s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":521,"lbm_read_time_us":18589,"lbm_reads_lt_1ms":871,"lbm_write_time_us":41055,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":20992,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:17:24.153012  5953 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:24.153450  5953 tablet_replica.cc:333] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb: stopping tablet replica
I20260812 06:17:24.153623  5953 raft_consensus.cc:2243] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:24.153832  5953 raft_consensus.cc:2272] T 5392e10da56d4ef8ae4811b210a94725 P a8c90524614e4e2381748866846a17bb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:24.170804  5953 tablet_server.cc:196] TabletServer@127.5.208.65:0 shutdown complete.
I20260812 06:17:24.223778  5953 master.cc:562] Master@127.5.208.126:38857 shutting down...
I20260812 06:17:24.227495  5953 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:24.227706  5953 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:24.227792  5953 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6c3bbc769a9847cfa56d238392c3d56f: stopping tablet replica
I20260812 06:17:24.240258  5953 master.cc:584] Master@127.5.208.126:38857 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5545 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11013 ms total)

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