[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:19.535656 21608 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.26.62:44133
I20260812 06:20:19.536792 21608 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:19.537444 21608 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.544375 21614 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.544427 21608 server_base.cc:1061] running on GCE node
W20260812 06:20:19.544628 21617 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.544692 21615 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.545281 21608 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.545389 21608 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.545436 21608 hybrid_clock.cc:648] HybridClock initialized: now 1786515619545433 us; error 0 us; skew 500 ppm
I20260812 06:20:19.547339 21608 webserver.cc:533] Webserver started at http://127.21.26.62:36689/ using document root <none> and password file <none>
I20260812 06:20:19.547904 21608 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.547995 21608 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.548260 21608 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.550012 21608 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/master-0-root/instance:
uuid: "c10e2cd0c7b9443699cc3ed1e5b50282"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-ncp9"
I20260812 06:20:19.553824 21608 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:19.556229 21628 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.557483 21608 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:19.557616 21608 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/master-0-root
uuid: "c10e2cd0c7b9443699cc3ed1e5b50282"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-ncp9"
I20260812 06:20:19.557717 21608 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.587229 21608 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.587980 21608 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:19.588156 21608 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.596186 21608 rpc_server.cc:307] RPC server started. Bound to: 127.21.26.62:44133
I20260812 06:20:19.596222 21739 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.26.62:44133 every 8 connection(s)
I20260812 06:20:19.598706 21740 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.604790 21740 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: Bootstrap starting.
I20260812 06:20:19.608243 21740 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.609352 21740 log.cc:826] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:19.611745 21740 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: No bootstrap required, opened a new log
I20260812 06:20:19.614967 21740 raft_consensus.cc:359] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER }
I20260812 06:20:19.615166 21740 raft_consensus.cc:385] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.615234 21740 raft_consensus.cc:740] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c10e2cd0c7b9443699cc3ed1e5b50282, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.615928 21740 consensus_queue.cc:260] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [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: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER }
I20260812 06:20:19.616092 21740 raft_consensus.cc:399] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.616144 21740 raft_consensus.cc:493] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.616250 21740 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.617125 21740 raft_consensus.cc:515] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER }
I20260812 06:20:19.617563 21740 leader_election.cc:304] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [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: c10e2cd0c7b9443699cc3ed1e5b50282; no voters: 
I20260812 06:20:19.617882 21740 leader_election.cc:290] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.618052 21745 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.618299 21745 raft_consensus.cc:697] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 1 LEADER]: Becoming Leader. State: Replica: c10e2cd0c7b9443699cc3ed1e5b50282, State: Running, Role: LEADER
I20260812 06:20:19.618738 21745 consensus_queue.cc:237] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [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: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER }
I20260812 06:20:19.618971 21740 sys_catalog.cc:565] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.620818 21747 sys_catalog.cc:455] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c10e2cd0c7b9443699cc3ed1e5b50282. Latest consensus state: current_term: 1 leader_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER } }
I20260812 06:20:19.620833 21746 sys_catalog.cc:455] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10e2cd0c7b9443699cc3ed1e5b50282" member_type: VOTER } }
I20260812 06:20:19.621011 21746 sys_catalog.cc:458] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.621011 21747 sys_catalog.cc:458] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.621333 21608 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:19.623536 21773 catalog_manager.cc:1594] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:19.623606 21773 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:19.623675 21772 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.624452 21772 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.629748 21772 catalog_manager.cc:1383] Generated new cluster ID: 27fb42fc5bff4053a8fd97a8c2e4a6f9
I20260812 06:20:19.629820 21772 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.644634 21772 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.645604 21772 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.657644 21772 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: Generated new TSK 0
I20260812 06:20:19.658370 21772 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.686300 21608 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.689159 21782 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.689234 21783 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.689159 21788 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.689533 21608 server_base.cc:1061] running on GCE node
I20260812 06:20:19.689764 21608 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.689814 21608 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.689836 21608 hybrid_clock.cc:648] HybridClock initialized: now 1786515619689836 us; error 0 us; skew 500 ppm
I20260812 06:20:19.690801 21608 webserver.cc:533] Webserver started at http://127.21.26.1:35913/ using document root <none> and password file <none>
I20260812 06:20:19.690992 21608 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.691056 21608 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.691128 21608 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.691570 21608 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/instance:
uuid: "440f8e9a168843dbabc6b873680c81f9"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-ncp9"
I20260812 06:20:19.693459 21608 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.694602 21799 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.694844 21608 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.694923 21608 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root
uuid: "440f8e9a168843dbabc6b873680c81f9"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-ncp9"
I20260812 06:20:19.695007 21608 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.720340 21608 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.720958 21608 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.721537 21608 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.722605 21608 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.722672 21608 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.722739 21608 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.722769 21608 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.729494 21608 rpc_server.cc:307] RPC server started. Bound to: 127.21.26.1:44113
I20260812 06:20:19.729542 21935 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.26.1:44113 every 8 connection(s)
I20260812 06:20:19.743899 21936 heartbeater.cc:344] Connected to a master server at 127.21.26.62:44133
I20260812 06:20:19.744189 21936 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.744724 21936 heartbeater.cc:507] Master 127.21.26.62:44133 requested a full tablet report, sending...
I20260812 06:20:19.746344 21663 ts_manager.cc:194] Registered new tserver with Master: 440f8e9a168843dbabc6b873680c81f9 (127.21.26.1:44113)
I20260812 06:20:19.746935 21608 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016852188s
I20260812 06:20:19.747888 21663 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34592
I20260812 06:20:19.757177 21663 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34600:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:19.772042 21857 tablet_service.cc:1511] Processing CreateTablet for tablet 6d4fe0e656244732986555b9e85b87fe (DEFAULT_TABLE table=heavy-update-compaction-test [id=6fcb1eff577b46939e94de179ef7d87e]), partition=
I20260812 06:20:19.772536 21857 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6d4fe0e656244732986555b9e85b87fe. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.774812 21952 tablet_bootstrap.cc:492] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Bootstrap starting.
I20260812 06:20:19.776098 21952 tablet_bootstrap.cc:654] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.777258 21952 tablet_bootstrap.cc:492] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: No bootstrap required, opened a new log
I20260812 06:20:19.777361 21952 ts_tablet_manager.cc:1403] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.777837 21952 raft_consensus.cc:359] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "440f8e9a168843dbabc6b873680c81f9" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 44113 } }
I20260812 06:20:19.777940 21952 raft_consensus.cc:385] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.777973 21952 raft_consensus.cc:740] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 440f8e9a168843dbabc6b873680c81f9, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.778117 21952 consensus_queue.cc:260] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [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: "440f8e9a168843dbabc6b873680c81f9" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 44113 } }
I20260812 06:20:19.778213 21952 raft_consensus.cc:399] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.778258 21952 raft_consensus.cc:493] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.778307 21952 raft_consensus.cc:3060] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.779026 21952 raft_consensus.cc:515] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "440f8e9a168843dbabc6b873680c81f9" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 44113 } }
I20260812 06:20:19.779173 21952 leader_election.cc:304] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [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: 440f8e9a168843dbabc6b873680c81f9; no voters: 
I20260812 06:20:19.779397 21952 leader_election.cc:290] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.779529 21958 raft_consensus.cc:2804] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.779803 21958 raft_consensus.cc:697] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 1 LEADER]: Becoming Leader. State: Replica: 440f8e9a168843dbabc6b873680c81f9, State: Running, Role: LEADER
I20260812 06:20:19.779862 21952 ts_tablet_manager.cc:1434] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:20:19.780221 21958 consensus_queue.cc:237] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [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: "440f8e9a168843dbabc6b873680c81f9" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 44113 } }
I20260812 06:20:19.780333 21936 heartbeater.cc:499] Master 127.21.26.62:44133 was elected leader, sending a full tablet report...
I20260812 06:20:19.782934 21663 catalog_manager.cc:5719] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 440f8e9a168843dbabc6b873680c81f9 (127.21.26.1). New cstate: current_term: 1 leader_uuid: "440f8e9a168843dbabc6b873680c81f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "440f8e9a168843dbabc6b873680c81f9" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 44113 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.848693 21608 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.015s	sys 0.008s
I20260812 06:20:19.984208 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushMRSOp(6d4fe0e656244732986555b9e85b87fe): perf score=19.054940
I20260812 06:20:20.167176 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushMRSOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.183s	user 0.152s	sys 0.028s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":184,"delete_count":0,"dirs.queue_time_us":736,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1319,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46252,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":92,"threads_started":1,"update_count":1550}
I20260812 06:20:20.168916 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling LogGCOp(6d4fe0e656244732986555b9e85b87fe): free 20743880 bytes of WAL
I20260812 06:20:20.169410 21809 log_reader.cc:385] T 6d4fe0e656244732986555b9e85b87fe: removed 2 log segments from log reader
I20260812 06:20:20.169548 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000001 (ops 1-6)
I20260812 06:20:20.169658 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000002 (ops 7-11)
I20260812 06:20:20.176067 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: LogGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:20.176628 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe): 16411392 bytes on disk
I20260812 06:20:20.177459 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.178045 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:20.207890 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.030s	user 0.002s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.208429 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:20.218122 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3484,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.218649 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:20.402067 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.183s	user 0.120s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":570,"lbm_read_time_us":12656,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31143,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":315,"threads_started":5,"update_count":2500}
I20260812 06:20:20.402622 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:20.450019 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.047s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20919,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.450713 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:20.463668 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.464264 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:20.597658 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.133s	user 0.116s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":904,"lbm_read_time_us":9914,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25468,"lbm_writes_lt_1ms":443,"mutex_wait_us":373,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:20:20.598201 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:20.632939 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.032s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13210,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.633486 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:20.649850 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.650367 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:20.776335 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.126s	user 0.100s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":9085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23450,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.776965 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:20.822623 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.045s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18323,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.823275 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:20.839932 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.840523 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:20.961441 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.121s	user 0.089s	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":282,"lbm_read_time_us":8481,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24251,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:20:20.961987 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:21.008276 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.046s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16463,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.008961 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.019840 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.020368 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:21.181139 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.161s	user 0.127s	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":810,"lbm_read_time_us":11707,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27190,"lbm_writes_lt_1ms":443,"mutex_wait_us":364,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:20:21.181820 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:21.218453 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14826,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.218941 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.230293 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.231073 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:21.360528 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.129s	user 0.091s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":9476,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25128,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:20:21.361114 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=10.126437
I20260812 06:20:21.404883 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.044s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17372,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.405501 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.416224 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.416775 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushMRSOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:21.445129 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushMRSOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.445956 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling LogGCOp(6d4fe0e656244732986555b9e85b87fe): free 112239255 bytes of WAL
I20260812 06:20:21.446234 21809 log_reader.cc:385] T 6d4fe0e656244732986555b9e85b87fe: removed 11 log segments from log reader
I20260812 06:20:21.446290 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000003 (ops 12-16)
I20260812 06:20:21.446374 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000004 (ops 17-21)
I20260812 06:20:21.446414 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000005 (ops 22-26)
I20260812 06:20:21.446437 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000006 (ops 27-30)
I20260812 06:20:21.446458 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000007 (ops 31-35)
I20260812 06:20:21.446478 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000008 (ops 36-40)
I20260812 06:20:21.446508 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000009 (ops 41-45)
I20260812 06:20:21.446533 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000010 (ops 46-50)
I20260812 06:20:21.446576 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000011 (ops 51-55)
I20260812 06:20:21.446599 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000012 (ops 56-60)
I20260812 06:20:21.446619 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000013 (ops 61-65)
I20260812 06:20:21.473868 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: LogGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:21.474395 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe): 462 bytes on disk
I20260812 06:20:21.474835 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.475345 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=3.181125
I20260812 06:20:21.488098 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.488564 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.498392 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3422,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.498838 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:21.676367 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.177s	user 0.141s	sys 0.030s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":292,"lbm_read_time_us":12438,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34974,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:21.677018 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:21.725852 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.726434 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.737334 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.737874 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:21.893567 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.156s	user 0.100s	sys 0.036s 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":550,"lbm_read_time_us":10099,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27169,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:20:21.894301 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:21.944149 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.050s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.944725 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:21.955928 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.956596 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:22.137733 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.181s	user 0.109s	sys 0.070s 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":335,"lbm_read_time_us":11815,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33774,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.138293 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=11.118625
I20260812 06:20:22.180949 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.042s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12922847,"delete_count":0,"lbm_write_time_us":19143,"lbm_writes_lt_1ms":318,"reinsert_count":0,"update_count":1575}
I20260812 06:20:22.181460 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:22.203469 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.022s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3785,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:22.203984 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:22.214650 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.215155 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:22.396814 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.181s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774786,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":840,"lbm_read_time_us":13171,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31870,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:22.397341 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:22.453537 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.056s	user 0.043s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.454173 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:22.464952 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.465570 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:22.630554 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.165s	user 0.110s	sys 0.054s 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":1022,"lbm_read_time_us":12005,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29324,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:20:22.631091 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:22.690908 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.060s	user 0.029s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22537,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.691646 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:22.705096 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.705600 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushMRSOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:22.733832 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushMRSOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1648,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1902,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:22.734615 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling LogGCOp(6d4fe0e656244732986555b9e85b87fe): free 112239375 bytes of WAL
I20260812 06:20:22.734862 21809 log_reader.cc:385] T 6d4fe0e656244732986555b9e85b87fe: removed 11 log segments from log reader
I20260812 06:20:22.734922 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000014 (ops 66-70)
I20260812 06:20:22.734962 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000015 (ops 71-75)
I20260812 06:20:22.734997 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000016 (ops 76-80)
I20260812 06:20:22.735031 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000017 (ops 81-85)
I20260812 06:20:22.735054 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000018 (ops 86-90)
I20260812 06:20:22.735082 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000019 (ops 91-95)
I20260812 06:20:22.735110 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000020 (ops 96-100)
I20260812 06:20:22.735139 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000021 (ops 101-105)
I20260812 06:20:22.735172 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000022 (ops 106-110)
I20260812 06:20:22.735200 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000023 (ops 111-114)
I20260812 06:20:22.735230 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000024 (ops 115-119)
I20260812 06:20:22.763092 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: LogGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:22.763677 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe): 447 bytes on disk
I20260812 06:20:22.764237 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.764948 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=3.181125
I20260812 06:20:22.779235 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.014s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.779708 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling LogGCOp(6d4fe0e656244732986555b9e85b87fe): free 8767121 bytes of WAL
I20260812 06:20:22.779911 21809 log_reader.cc:385] T 6d4fe0e656244732986555b9e85b87fe: removed 1 log segments from log reader
I20260812 06:20:22.779968 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000025 (ops 120-124)
I20260812 06:20:22.782171 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: LogGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:22.782514 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:22.797498 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5420,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.798244 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:23.007727 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.209s	user 0.132s	sys 0.070s 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":1119,"lbm_read_time_us":14885,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37159,"lbm_writes_lt_1ms":743,"mutex_wait_us":337,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:20:23.008262 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=18.063937
I20260812 06:20:23.069773 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.061s	user 0.035s	sys 0.025s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28367,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.070354 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:23.092005 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.092532 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:23.103732 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.104453 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:23.290371 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.186s	user 0.146s	sys 0.037s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":253,"lbm_read_time_us":13635,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38093,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":3500}
I20260812 06:20:23.293423 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=15.087375
I20260812 06:20:23.357118 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.063s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16820146,"delete_count":0,"lbm_write_time_us":21918,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:23.357653 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=6.157687
I20260812 06:20:23.381625 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.024s	user 0.017s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9167,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:23.382121 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:23.560937 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.179s	user 0.127s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":13171,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34799,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:23.561591 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:23.611253 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.049s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23007,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.612067 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:23.638576 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.026s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:20:23.639056 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:23.650121 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.650717 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:23.823011 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.172s	user 0.112s	sys 0.060s 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":511,"lbm_read_time_us":11848,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36136,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:20:23.823570 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:23.870922 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.047s	user 0.037s	sys 0.007s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21109,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.871562 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:23.888994 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.017s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.889497 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:24.035120 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.145s	user 0.107s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":650,"lbm_read_time_us":9440,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27299,"lbm_writes_lt_1ms":543,"mutex_wait_us":383,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:24.037395 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=14.095187
I20260812 06:20:24.095333 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.058s	user 0.031s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25249,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.095817 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:24.107223 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.107990 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushMRSOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:24.136058 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushMRSOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1631,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:24.136795 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling LogGCOp(6d4fe0e656244732986555b9e85b87fe): free 127961355 bytes of WAL
I20260812 06:20:24.137045 21809 log_reader.cc:385] T 6d4fe0e656244732986555b9e85b87fe: removed 12 log segments from log reader
I20260812 06:20:24.137094 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000026 (ops 125-129)
I20260812 06:20:24.137125 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000027 (ops 130-134)
I20260812 06:20:24.137156 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000028 (ops 135-139)
I20260812 06:20:24.137194 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000029 (ops 140-144)
I20260812 06:20:24.137220 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000030 (ops 145-149)
I20260812 06:20:24.137251 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000031 (ops 150-154)
I20260812 06:20:24.137285 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000032 (ops 155-159)
I20260812 06:20:24.137317 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000033 (ops 160-164)
I20260812 06:20:24.137351 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000034 (ops 165-169)
I20260812 06:20:24.137382 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000035 (ops 170-174)
I20260812 06:20:24.137415 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000036 (ops 175-179)
I20260812 06:20:24.137445 21809 log.cc:1079] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/6d4fe0e656244732986555b9e85b87fe/wal-000000037 (ops 180-184)
I20260812 06:20:24.164948 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: LogGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:24.165370 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe): 472 bytes on disk
I20260812 06:20:24.165913 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: UndoDeltaBlockGCOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.166725 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=3.181125
I20260812 06:20:24.182361 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.182940 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:24.193163 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.193674 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:24.416666 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.223s	user 0.135s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2711,"lbm_read_time_us":15395,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39447,"lbm_writes_lt_1ms":743,"mutex_wait_us":2101,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:20:24.417676 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=18.063937
I20260812 06:20:24.475248 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.057s	user 0.028s	sys 0.026s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25168,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.476012 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe): perf score=2.188937
I20260812 06:20:24.494532 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: FlushDeltaMemStoresOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.495108 21938 maintenance_manager.cc:419] P 440f8e9a168843dbabc6b873680c81f9: Scheduling MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe): perf score=1.000000
I20260812 06:20:24.508651 21608 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.660s	user 1.708s	sys 0.111s
I20260812 06:20:24.567565 21608 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.058s	user 0.001s	sys 0.000s
I20260812 06:20:24.568228 21608 tablet_server.cc:179] TabletServer@127.21.26.1:0 shutting down...
I20260812 06:20:24.655095 21809 maintenance_manager.cc:643] P 440f8e9a168843dbabc6b873680c81f9: MajorDeltaCompactionOp(6d4fe0e656244732986555b9e85b87fe) complete. Timing: real 0.160s	user 0.107s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":316,"dirs.run_cpu_time_us":2691,"dirs.run_wall_time_us":19648,"lbm_read_time_us":11909,"lbm_reads_lt_1ms":660,"lbm_write_time_us":28387,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:20:24.657250 21608 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.657701 21608 tablet_replica.cc:333] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9: stopping tablet replica
I20260812 06:20:24.657979 21608 raft_consensus.cc:2243] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.658245 21608 raft_consensus.cc:2272] T 6d4fe0e656244732986555b9e85b87fe P 440f8e9a168843dbabc6b873680c81f9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.675262 21608 tablet_server.cc:196] TabletServer@127.21.26.1:0 shutdown complete.
I20260812 06:20:24.702373 21608 master.cc:562] Master@127.21.26.62:44133 shutting down...
I20260812 06:20:24.705886 21608 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.706084 21608 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.706164 21608 tablet_replica.cc:333] T 00000000000000000000000000000000 P c10e2cd0c7b9443699cc3ed1e5b50282: stopping tablet replica
I20260812 06:20:24.718617 21608 master.cc:584] Master@127.21.26.62:44133 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5266 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:24.801766 21608 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.26.62:44045
I20260812 06:20:24.802150 21608 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.804515 21986 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:24.804529 21990 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:24.804617 21608 server_base.cc:1061] running on GCE node
W20260812 06:20:24.804714 21995 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:24.804961 21608 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.805014 21608 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:24.805045 21608 hybrid_clock.cc:648] HybridClock initialized: now 1786515624805045 us; error 0 us; skew 500 ppm
I20260812 06:20:24.805816 21608 webserver.cc:533] Webserver started at http://127.21.26.62:36537/ using document root <none> and password file <none>
I20260812 06:20:24.805970 21608 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.806021 21608 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.806123 21608 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.806494 21608 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/master-0-root/instance:
uuid: "75dd176f406648c8b57b5717a366347b"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-ncp9"
I20260812 06:20:24.807976 21608 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:24.808966 22004 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.809207 21608 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:24.809275 21608 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/master-0-root
uuid: "75dd176f406648c8b57b5717a366347b"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-ncp9"
I20260812 06:20:24.809341 21608 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:24.815438 21608 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.815840 21608 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.819919 21608 rpc_server.cc:307] RPC server started. Bound to: 127.21.26.62:44045
I20260812 06:20:24.831920 22125 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.26.62:44045 every 8 connection(s)
I20260812 06:20:24.832444 22128 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.834422 22128 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b: Bootstrap starting.
I20260812 06:20:24.835289 22128 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.836375 22128 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b: No bootstrap required, opened a new log
I20260812 06:20:24.836781 22128 raft_consensus.cc:359] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75dd176f406648c8b57b5717a366347b" member_type: VOTER }
I20260812 06:20:24.836870 22128 raft_consensus.cc:385] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.836937 22128 raft_consensus.cc:740] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 75dd176f406648c8b57b5717a366347b, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.837091 22128 consensus_queue.cc:260] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [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: "75dd176f406648c8b57b5717a366347b" member_type: VOTER }
I20260812 06:20:24.837172 22128 raft_consensus.cc:399] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.837206 22128 raft_consensus.cc:493] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.837255 22128 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.837934 22128 raft_consensus.cc:515] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75dd176f406648c8b57b5717a366347b" member_type: VOTER }
I20260812 06:20:24.838054 22128 leader_election.cc:304] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [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: 75dd176f406648c8b57b5717a366347b; no voters: 
I20260812 06:20:24.838259 22128 leader_election.cc:290] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.838409 22132 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.838670 22132 raft_consensus.cc:697] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 1 LEADER]: Becoming Leader. State: Replica: 75dd176f406648c8b57b5717a366347b, State: Running, Role: LEADER
I20260812 06:20:24.838757 22128 sys_catalog.cc:565] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:24.838873 22132 consensus_queue.cc:237] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [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: "75dd176f406648c8b57b5717a366347b" member_type: VOTER }
I20260812 06:20:24.839323 22136 sys_catalog.cc:455] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 75dd176f406648c8b57b5717a366347b. Latest consensus state: current_term: 1 leader_uuid: "75dd176f406648c8b57b5717a366347b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75dd176f406648c8b57b5717a366347b" member_type: VOTER } }
I20260812 06:20:24.839481 22136 sys_catalog.cc:458] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.839349 22135 sys_catalog.cc:455] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "75dd176f406648c8b57b5717a366347b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75dd176f406648c8b57b5717a366347b" member_type: VOTER } }
I20260812 06:20:24.839784 22135 sys_catalog.cc:458] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.839994 22148 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:24.840984 22148 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:24.841180 21608 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:24.842864 22148 catalog_manager.cc:1383] Generated new cluster ID: a3932aa629184aac8fa102fbc2dcb4ac
I20260812 06:20:24.842921 22148 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:24.857697 22148 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:24.858302 22148 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:24.875057 22148 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b: Generated new TSK 0
I20260812 06:20:24.875276 22148 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:24.906076 21608 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.908479 22166 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:24.908501 22165 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:24.908543 22168 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:24.908768 21608 server_base.cc:1061] running on GCE node
I20260812 06:20:24.908972 21608 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.909015 21608 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:24.909036 21608 hybrid_clock.cc:648] HybridClock initialized: now 1786515624909036 us; error 0 us; skew 500 ppm
I20260812 06:20:24.909962 21608 webserver.cc:533] Webserver started at http://127.21.26.1:45273/ using document root <none> and password file <none>
I20260812 06:20:24.910133 21608 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.910208 21608 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.910295 21608 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.910718 21608 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/instance:
uuid: "2752bafb79114f4baa0b816ba06978c8"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-ncp9"
I20260812 06:20:24.912195 21608 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:24.913209 22178 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.913465 21608 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:24.913539 21608 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root
uuid: "2752bafb79114f4baa0b816ba06978c8"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-ncp9"
I20260812 06:20:24.913599 21608 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:24.920682 21608 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.921065 21608 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.921319 21608 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.921762 21608 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.921799 21608 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.921833 21608 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.921860 21608 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.926172 21608 rpc_server.cc:307] RPC server started. Bound to: 127.21.26.1:43657
I20260812 06:20:24.926194 22289 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.26.1:43657 every 8 connection(s)
I20260812 06:20:24.934185 22290 heartbeater.cc:344] Connected to a master server at 127.21.26.62:44045
I20260812 06:20:24.934309 22290 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.934599 22290 heartbeater.cc:507] Master 127.21.26.62:44045 requested a full tablet report, sending...
I20260812 06:20:24.935321 22037 ts_manager.cc:194] Registered new tserver with Master: 2752bafb79114f4baa0b816ba06978c8 (127.21.26.1:43657)
I20260812 06:20:24.935505 21608 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008904321s
I20260812 06:20:24.936156 22037 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38926
I20260812 06:20:24.942698 22037 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38928:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:24.951138 22224 tablet_service.cc:1511] Processing CreateTablet for tablet 30e58b7a14d54a81a9cb659f9106d74b (DEFAULT_TABLE table=heavy-update-compaction-test [id=d7543fc1dd6d421483e8df37dda1962a]), partition=
I20260812 06:20:24.951413 22224 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 30e58b7a14d54a81a9cb659f9106d74b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.953539 22315 tablet_bootstrap.cc:492] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Bootstrap starting.
I20260812 06:20:24.954447 22315 tablet_bootstrap.cc:654] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.955513 22315 tablet_bootstrap.cc:492] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: No bootstrap required, opened a new log
I20260812 06:20:24.955600 22315 ts_tablet_manager.cc:1403] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:24.956010 22315 raft_consensus.cc:359] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2752bafb79114f4baa0b816ba06978c8" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 43657 } }
I20260812 06:20:24.956101 22315 raft_consensus.cc:385] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.956151 22315 raft_consensus.cc:740] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2752bafb79114f4baa0b816ba06978c8, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.956326 22315 consensus_queue.cc:260] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [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: "2752bafb79114f4baa0b816ba06978c8" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 43657 } }
I20260812 06:20:24.956421 22315 raft_consensus.cc:399] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.956465 22315 raft_consensus.cc:493] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.956512 22315 raft_consensus.cc:3060] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.957391 22315 raft_consensus.cc:515] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2752bafb79114f4baa0b816ba06978c8" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 43657 } }
I20260812 06:20:24.957512 22315 leader_election.cc:304] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [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: 2752bafb79114f4baa0b816ba06978c8; no voters: 
I20260812 06:20:24.957679 22315 leader_election.cc:290] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.957813 22322 raft_consensus.cc:2804] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.957999 22315 ts_tablet_manager.cc:1434] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:24.958050 22290 heartbeater.cc:499] Master 127.21.26.62:44045 was elected leader, sending a full tablet report...
I20260812 06:20:24.958030 22322 raft_consensus.cc:697] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 1 LEADER]: Becoming Leader. State: Replica: 2752bafb79114f4baa0b816ba06978c8, State: Running, Role: LEADER
I20260812 06:20:24.958226 22322 consensus_queue.cc:237] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [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: "2752bafb79114f4baa0b816ba06978c8" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 43657 } }
I20260812 06:20:24.959527 22037 catalog_manager.cc:5719] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2752bafb79114f4baa0b816ba06978c8 (127.21.26.1). New cstate: current_term: 1 leader_uuid: "2752bafb79114f4baa0b816ba06978c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2752bafb79114f4baa0b816ba06978c8" member_type: VOTER last_known_addr { host: "127.21.26.1" port: 43657 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.018333 21608 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.010s	sys 0.012s
I20260812 06:20:25.177194 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=19.054940
I20260812 06:20:25.320219 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.142s	user 0.095s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36342,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:20:25.321204 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling LogGCOp(30e58b7a14d54a81a9cb659f9106d74b): free 20743880 bytes of WAL
I20260812 06:20:25.321461 22183 log_reader.cc:385] T 30e58b7a14d54a81a9cb659f9106d74b: removed 2 log segments from log reader
I20260812 06:20:25.321511 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000001 (ops 1-6)
I20260812 06:20:25.321552 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000002 (ops 7-11)
I20260812 06:20:25.326414 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: LogGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:25.326862 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:25.338562 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.339005 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b): 16821647 bytes on disk
I20260812 06:20:25.339417 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.339811 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:25.476284 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.136s	user 0.097s	sys 0.039s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303018,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":638,"lbm_read_time_us":9667,"lbm_reads_lt_1ms":454,"lbm_write_time_us":24705,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":293,"threads_started":5,"update_count":1950}
I20260812 06:20:25.476835 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=10.126437
I20260812 06:20:25.514355 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.037s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16230,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.514930 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:25.531015 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.531608 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:25.677582 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.146s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1173,"lbm_read_time_us":9995,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23280,"lbm_writes_lt_1ms":443,"mutex_wait_us":398,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":2000}
I20260812 06:20:25.678205 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=11.118625
I20260812 06:20:25.717336 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16968,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.717844 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:25.734731 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.735227 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:25.745152 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3623,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.745613 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:25.929741 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.184s	user 0.128s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1077,"lbm_read_time_us":10376,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31331,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:25.930330 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:25.985566 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.055s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.986002 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:25.996358 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.996950 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:26.159574 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.162s	user 0.120s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":11113,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31026,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:26.160210 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=11.118625
I20260812 06:20:26.219043 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.059s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18933,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.219581 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=6.157687
I20260812 06:20:26.245342 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.026s	user 0.010s	sys 0.015s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10585,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:26.245971 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:26.401631 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.155s	user 0.127s	sys 0.018s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":10013,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26943,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:20:26.402211 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:26.452358 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.050s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20557,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.452966 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:26.464146 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.464881 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:26.626063 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.161s	user 0.127s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":12096,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30038,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:20:26.626573 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:26.675618 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.049s	user 0.020s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17141,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.676239 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:26.687932 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.688630 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:26.718468 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1318,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1802,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:26.719115 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling LogGCOp(30e58b7a14d54a81a9cb659f9106d74b): free 133024309 bytes of WAL
I20260812 06:20:26.719360 22183 log_reader.cc:385] T 30e58b7a14d54a81a9cb659f9106d74b: removed 13 log segments from log reader
I20260812 06:20:26.719442 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000003 (ops 12-16)
I20260812 06:20:26.719496 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000004 (ops 17-21)
I20260812 06:20:26.719555 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000005 (ops 22-26)
I20260812 06:20:26.719594 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000006 (ops 27-31)
I20260812 06:20:26.719635 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000007 (ops 32-36)
I20260812 06:20:26.719660 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000008 (ops 37-41)
I20260812 06:20:26.719683 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000009 (ops 42-46)
I20260812 06:20:26.719712 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000010 (ops 47-51)
I20260812 06:20:26.719735 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000011 (ops 52-56)
I20260812 06:20:26.719758 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000012 (ops 57-61)
I20260812 06:20:26.719781 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000013 (ops 62-66)
I20260812 06:20:26.719811 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000014 (ops 67-70)
I20260812 06:20:26.719837 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000015 (ops 71-75)
I20260812 06:20:26.744706 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: LogGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:26.745191 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=3.181125
I20260812 06:20:26.756683 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:26.757206 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:26.766741 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3397,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.767186 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b): 492 bytes on disk
I20260812 06:20:26.767716 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.768275 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:26.950768 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.182s	user 0.150s	sys 0.032s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":437,"lbm_read_time_us":12929,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37739,"lbm_writes_lt_1ms":743,"mutex_wait_us":18,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":116096,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:26.954382 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:26.994109 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17288,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:26.994699 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:27.008275 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.009583 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:27.168069 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.158s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1632,"lbm_read_time_us":9310,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29661,"lbm_writes_lt_1ms":543,"mutex_wait_us":417,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:27.168799 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:27.219616 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.051s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.220178 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:27.359459 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.139s	user 0.086s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713150,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1076,"lbm_read_time_us":10850,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21617,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:27.359999 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:27.422544 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.062s	user 0.025s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23802,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.423244 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:27.438632 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.439190 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:27.623878 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.184s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1542,"lbm_read_time_us":13199,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29662,"lbm_writes_lt_1ms":543,"mutex_wait_us":357,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:27.624419 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:27.681943 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20065,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.682619 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:27.698731 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.699295 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:27.889803 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.190s	user 0.138s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1070,"lbm_read_time_us":13159,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28449,"lbm_writes_lt_1ms":543,"mutex_wait_us":249,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:20:27.890321 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:27.943986 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.054s	user 0.018s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25023,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.944626 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:27.956282 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.956843 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:28.137010 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.180s	user 0.116s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1108,"lbm_read_time_us":11817,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29707,"lbm_writes_lt_1ms":543,"mutex_wait_us":353,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:20:28.137624 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:28.194191 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.056s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24972,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.194846 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:28.211557 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.212080 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:28.240005 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275446,"cfile_init":1,"dirs.queue_time_us":35,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1581,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1753,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:28.240724 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling LogGCOp(30e58b7a14d54a81a9cb659f9106d74b): free 124710379 bytes of WAL
I20260812 06:20:28.240969 22183 log_reader.cc:385] T 30e58b7a14d54a81a9cb659f9106d74b: removed 12 log segments from log reader
I20260812 06:20:28.241015 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000016 (ops 76-80)
I20260812 06:20:28.241045 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000017 (ops 81-85)
I20260812 06:20:28.241078 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000018 (ops 86-90)
I20260812 06:20:28.241110 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000019 (ops 91-95)
I20260812 06:20:28.241143 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000020 (ops 96-100)
I20260812 06:20:28.241174 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000021 (ops 101-105)
I20260812 06:20:28.241204 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000022 (ops 106-110)
I20260812 06:20:28.241235 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000023 (ops 111-115)
I20260812 06:20:28.241266 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000024 (ops 116-120)
I20260812 06:20:28.241297 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000025 (ops 121-125)
I20260812 06:20:28.241326 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000026 (ops 126-130)
I20260812 06:20:28.241357 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000027 (ops 131-135)
I20260812 06:20:28.269399 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: LogGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:28.269804 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=3.181125
I20260812 06:20:28.295197 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.025s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5093,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.295681 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:28.305173 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3399,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.305666 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b): 482 bytes on disk
I20260812 06:20:28.306131 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b) 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:20:28.306639 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:28.540313 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.234s	user 0.141s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":291,"lbm_read_time_us":18073,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35070,"lbm_writes_lt_1ms":743,"mutex_wait_us":102,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:20:28.540874 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=18.063937
I20260812 06:20:28.594259 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.053s	user 0.034s	sys 0.013s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":21574,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.594830 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:28.759001 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.164s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815568,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":996,"lbm_read_time_us":13181,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27371,"lbm_writes_lt_1ms":543,"mutex_wait_us":340,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:28.759550 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:28.815099 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.055s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19989,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.815872 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:28.831359 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5723,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.832027 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:29.008246 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.176s	user 0.116s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":12837,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29926,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:29.015388 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=15.087375
I20260812 06:20:29.078071 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.061s	user 0.044s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21879,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:29.080314 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.100649 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.020s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.101213 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.112535 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.113147 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:29.330473 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.217s	user 0.124s	sys 0.092s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1651,"lbm_read_time_us":16192,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35376,"lbm_writes_lt_1ms":643,"mutex_wait_us":611,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":3000}
I20260812 06:20:29.331012 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:29.390038 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.059s	user 0.046s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.390653 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.415660 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.025s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.416150 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.426455 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.426966 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:29.630203 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.203s	user 0.125s	sys 0.077s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":728,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32264,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3000}
I20260812 06:20:29.630900 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=14.095187
I20260812 06:20:29.678412 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.047s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22282,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.678952 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.690104 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.690845 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:29.720860 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushMRSOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.030s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1525,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1949,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:29.721756 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling LogGCOp(30e58b7a14d54a81a9cb659f9106d74b): free 124710510 bytes of WAL
I20260812 06:20:29.722045 22183 log_reader.cc:385] T 30e58b7a14d54a81a9cb659f9106d74b: removed 12 log segments from log reader
I20260812 06:20:29.722112 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000028 (ops 136-140)
I20260812 06:20:29.722159 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000029 (ops 141-145)
I20260812 06:20:29.722210 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000030 (ops 146-150)
I20260812 06:20:29.722240 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000031 (ops 151-155)
I20260812 06:20:29.722268 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000032 (ops 156-160)
I20260812 06:20:29.722293 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000033 (ops 161-165)
I20260812 06:20:29.722322 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000034 (ops 166-170)
I20260812 06:20:29.722354 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000035 (ops 171-175)
I20260812 06:20:29.722384 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000036 (ops 176-180)
I20260812 06:20:29.722411 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000037 (ops 181-185)
I20260812 06:20:29.722436 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000038 (ops 186-190)
I20260812 06:20:29.722461 22183 log.cc:1079] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: Deleting log segment in path: /tmp/dist-test-taskmR_4DS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619524512-21608-0/minicluster-data/ts-0-root/wals/30e58b7a14d54a81a9cb659f9106d74b/wal-000000039 (ops 191-195)
I20260812 06:20:29.752666 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: LogGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.031s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:20:29.753216 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=3.181125
I20260812 06:20:29.767206 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:29.768244 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b): 462 bytes on disk
I20260812 06:20:29.768818 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: UndoDeltaBlockGCOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.769898 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=2.188937
I20260812 06:20:29.779386 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: FlushDeltaMemStoresOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.009s	user 0.005s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3395,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.779974 22295 maintenance_manager.cc:419] P 2752bafb79114f4baa0b816ba06978c8: Scheduling MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b): perf score=1.000000
I20260812 06:20:29.812383 21608 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.794s	user 1.723s	sys 0.161s
I20260812 06:20:29.913900 21608 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.101s	user 0.002s	sys 0.000s
I20260812 06:20:29.914412 21608 tablet_server.cc:179] TabletServer@127.21.26.1:0 shutting down...
I20260812 06:20:29.985453 22183 maintenance_manager.cc:643] P 2752bafb79114f4baa0b816ba06978c8: MajorDeltaCompactionOp(30e58b7a14d54a81a9cb659f9106d74b) complete. Timing: real 0.205s	user 0.134s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":717,"lbm_read_time_us":15872,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31977,"lbm_writes_lt_1ms":743,"mutex_wait_us":93,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:20:29.987571 21608 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:29.987864 21608 tablet_replica.cc:333] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8: stopping tablet replica
I20260812 06:20:29.988031 21608 raft_consensus.cc:2243] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.988209 21608 raft_consensus.cc:2272] T 30e58b7a14d54a81a9cb659f9106d74b P 2752bafb79114f4baa0b816ba06978c8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.003115 21608 tablet_server.cc:196] TabletServer@127.21.26.1:0 shutdown complete.
I20260812 06:20:30.043337 21608 master.cc:562] Master@127.21.26.62:44045 shutting down...
I20260812 06:20:30.046581 21608 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.046780 21608 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.046847 21608 tablet_replica.cc:333] T 00000000000000000000000000000000 P 75dd176f406648c8b57b5717a366347b: stopping tablet replica
I20260812 06:20:30.059199 21608 master.cc:584] Master@127.21.26.62:44045 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5337 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10604 ms total)

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