[==========] 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:16:26.932910  8522 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.82.190:42951
I20260812 06:16:26.933965  8522 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:16:26.934633  8522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:26.941130  8536 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:16:26.941190  8522 server_base.cc:1061] running on GCE node
W20260812 06:16:26.941206  8537 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:16:26.941442  8545 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:16:26.942078  8522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:26.942209  8522 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:16:26.942274  8522 hybrid_clock.cc:648] HybridClock initialized: now 1786515386942272 us; error 0 us; skew 500 ppm
I20260812 06:16:26.944228  8522 webserver.cc:533] Webserver started at http://127.8.82.190:41281/ using document root <none> and password file <none>
I20260812 06:16:26.944825  8522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:26.944917  8522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:26.945186  8522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:26.947268  8522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/master-0-root/instance:
uuid: "fa97d3e392624a8696f2efd419a3cb8f"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-tk9z"
I20260812 06:16:26.951112  8522 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:26.953739  8552 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:16:26.955078  8522 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:16:26.955232  8522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/master-0-root
uuid: "fa97d3e392624a8696f2efd419a3cb8f"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-tk9z"
I20260812 06:16:26.955374  8522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-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:16:26.965956  8522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:26.966842  8522 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:16:26.967051  8522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:26.975973  8650 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.82.190:42951 every 8 connection(s)
I20260812 06:16:26.975970  8522 rpc_server.cc:307] RPC server started. Bound to: 127.8.82.190:42951
I20260812 06:16:26.978585  8651 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:16:26.984261  8651 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: Bootstrap starting.
I20260812 06:16:26.986771  8651 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:26.987771  8651 log.cc:826] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:26.989609  8651 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: No bootstrap required, opened a new log
I20260812 06:16:26.992765  8651 raft_consensus.cc:359] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER }
I20260812 06:16:26.992951  8651 raft_consensus.cc:385] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:26.992995  8651 raft_consensus.cc:740] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fa97d3e392624a8696f2efd419a3cb8f, State: Initialized, Role: FOLLOWER
I20260812 06:16:26.993692  8651 consensus_queue.cc:260] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [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: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER }
I20260812 06:16:26.993850  8651 raft_consensus.cc:399] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:26.993959  8651 raft_consensus.cc:493] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:26.994140  8651 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:26.995062  8651 raft_consensus.cc:515] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER }
I20260812 06:16:26.995543  8651 leader_election.cc:304] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [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: fa97d3e392624a8696f2efd419a3cb8f; no voters: 
I20260812 06:16:26.995893  8651 leader_election.cc:290] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:26.996044  8656 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:26.996313  8656 raft_consensus.cc:697] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 1 LEADER]: Becoming Leader. State: Replica: fa97d3e392624a8696f2efd419a3cb8f, State: Running, Role: LEADER
I20260812 06:16:26.996747  8656 consensus_queue.cc:237] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [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: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER }
I20260812 06:16:26.997027  8651 sys_catalog.cc:565] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:26.998771  8657 sys_catalog.cc:455] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fa97d3e392624a8696f2efd419a3cb8f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER } }
I20260812 06:16:26.998814  8659 sys_catalog.cc:455] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [sys.catalog]: SysCatalogTable state changed. Reason: New leader fa97d3e392624a8696f2efd419a3cb8f. Latest consensus state: current_term: 1 leader_uuid: "fa97d3e392624a8696f2efd419a3cb8f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa97d3e392624a8696f2efd419a3cb8f" member_type: VOTER } }
I20260812 06:16:26.998940  8659 sys_catalog.cc:458] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.998939  8657 sys_catalog.cc:458] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.999559  8522 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:27.001523  8691 catalog_manager.cc:1594] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:27.001616  8691 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:27.001691  8683 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:27.002568  8683 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:27.007534  8683 catalog_manager.cc:1383] Generated new cluster ID: 993d330d9ff94418b92a5b40a68a9f98
I20260812 06:16:27.007613  8683 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:27.014619  8683 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:27.015806  8683 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:27.030917  8683 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: Generated new TSK 0
I20260812 06:16:27.031831  8683 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:27.064519  8522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:27.067408  8696 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:16:27.067471  8698 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:16:27.067543  8700 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:16:27.067626  8522 server_base.cc:1061] running on GCE node
I20260812 06:16:27.067945  8522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:27.068006  8522 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:16:27.068032  8522 hybrid_clock.cc:648] HybridClock initialized: now 1786515387068031 us; error 0 us; skew 500 ppm
I20260812 06:16:27.069046  8522 webserver.cc:533] Webserver started at http://127.8.82.129:36785/ using document root <none> and password file <none>
I20260812 06:16:27.069218  8522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:27.069280  8522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:27.069367  8522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:27.069809  8522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/instance:
uuid: "4b690e5096de45bd86dcd1f70690e716"
format_stamp: "Formatted at 2026-08-12 06:16:27 on dist-test-slave-tk9z"
I20260812 06:16:27.071758  8522 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:27.073020  8708 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:16:27.073342  8522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:27.073421  8522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root
uuid: "4b690e5096de45bd86dcd1f70690e716"
format_stamp: "Formatted at 2026-08-12 06:16:27 on dist-test-slave-tk9z"
I20260812 06:16:27.073498  8522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-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:16:27.086865  8522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:27.087828  8522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:27.088552  8522 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:27.089695  8522 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:27.089771  8522 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:27.089829  8522 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:27.089852  8522 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:27.106170  8522 rpc_server.cc:307] RPC server started. Bound to: 127.8.82.129:36433
I20260812 06:16:27.106397  8819 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.82.129:36433 every 8 connection(s)
I20260812 06:16:27.119771  8820 heartbeater.cc:344] Connected to a master server at 127.8.82.190:42951
I20260812 06:16:27.120039  8820 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:27.120559  8820 heartbeater.cc:507] Master 127.8.82.190:42951 requested a full tablet report, sending...
I20260812 06:16:27.122299  8579 ts_manager.cc:194] Registered new tserver with Master: 4b690e5096de45bd86dcd1f70690e716 (127.8.82.129:36433)
I20260812 06:16:27.122875  8522 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015826818s
I20260812 06:16:27.123992  8579 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46162
I20260812 06:16:27.134219  8579 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46170:
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:16:27.150817  8754 tablet_service.cc:1511] Processing CreateTablet for tablet 32419373687f44e2a60a121de8a30017 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e59b1ad94fe34429a79009924b76ffc1]), partition=
I20260812 06:16:27.151362  8754 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 32419373687f44e2a60a121de8a30017. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:27.153677  8848 tablet_bootstrap.cc:492] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Bootstrap starting.
I20260812 06:16:27.155900  8848 tablet_bootstrap.cc:654] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:27.158298  8848 tablet_bootstrap.cc:492] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: No bootstrap required, opened a new log
I20260812 06:16:27.158461  8848 ts_tablet_manager.cc:1403] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Time spent bootstrapping tablet: real 0.005s	user 0.000s	sys 0.005s
I20260812 06:16:27.159895  8848 raft_consensus.cc:359] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b690e5096de45bd86dcd1f70690e716" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 36433 } }
I20260812 06:16:27.160086  8848 raft_consensus.cc:385] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:27.160161  8848 raft_consensus.cc:740] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4b690e5096de45bd86dcd1f70690e716, State: Initialized, Role: FOLLOWER
I20260812 06:16:27.160355  8848 consensus_queue.cc:260] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [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: "4b690e5096de45bd86dcd1f70690e716" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 36433 } }
I20260812 06:16:27.160494  8848 raft_consensus.cc:399] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:27.160557  8848 raft_consensus.cc:493] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:27.160645  8848 raft_consensus.cc:3060] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:27.162623  8848 raft_consensus.cc:515] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b690e5096de45bd86dcd1f70690e716" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 36433 } }
I20260812 06:16:27.162940  8848 leader_election.cc:304] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [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: 4b690e5096de45bd86dcd1f70690e716; no voters: 
I20260812 06:16:27.163309  8848 leader_election.cc:290] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:27.163455  8850 raft_consensus.cc:2804] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:27.163863  8850 raft_consensus.cc:697] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 1 LEADER]: Becoming Leader. State: Replica: 4b690e5096de45bd86dcd1f70690e716, State: Running, Role: LEADER
I20260812 06:16:27.163935  8848 ts_tablet_manager.cc:1434] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Time spent starting tablet: real 0.005s	user 0.000s	sys 0.005s
I20260812 06:16:27.164098  8850 consensus_queue.cc:237] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [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: "4b690e5096de45bd86dcd1f70690e716" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 36433 } }
I20260812 06:16:27.164148  8820 heartbeater.cc:499] Master 127.8.82.190:42951 was elected leader, sending a full tablet report...
I20260812 06:16:27.167831  8579 catalog_manager.cc:5719] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4b690e5096de45bd86dcd1f70690e716 (127.8.82.129). New cstate: current_term: 1 leader_uuid: "4b690e5096de45bd86dcd1f70690e716" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b690e5096de45bd86dcd1f70690e716" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 36433 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:27.267218  8522 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.088s	user 0.016s	sys 0.020s
I20260812 06:16:27.357550  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushMRSOp(32419373687f44e2a60a121de8a30017): perf score=10.125253
I20260812 06:16:27.477080  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushMRSOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.119s	user 0.100s	sys 0.016s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":238,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":822,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":24009,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":112,"threads_started":1,"update_count":1050}
I20260812 06:16:27.478120  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling LogGCOp(32419373687f44e2a60a121de8a30017): free 8725963 bytes of WAL
I20260812 06:16:27.478485  8716 log_reader.cc:385] T 32419373687f44e2a60a121de8a30017: removed 1 log segments from log reader
I20260812 06:16:27.478564  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000001 (ops 1-6)
I20260812 06:16:27.480506  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: LogGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:27.480847  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017): 8206537 bytes on disk
I20260812 06:16:27.481408  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.481793  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:27.497897  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5066,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.498529  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:27.637651  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.139s	user 0.100s	sys 0.025s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":533,"lbm_read_time_us":8090,"lbm_reads_lt_1ms":360,"lbm_write_time_us":23780,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7168,"thread_start_us":351,"threads_started":5,"update_count":1500}
I20260812 06:16:27.638209  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:27.693482  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.055s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18625,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.694015  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:27.709723  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.710485  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:27.859084  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.148s	user 0.091s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":841,"lbm_read_time_us":12268,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25889,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:16:27.859687  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:27.905928  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.046s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20941,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.906481  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:27.924819  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.018s	user 0.001s	sys 0.017s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.925395  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.074415  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.149s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":391,"lbm_read_time_us":10757,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26732,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.075027  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:28.122866  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23780,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.123322  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:28.135560  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.136018  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.273655  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.137s	user 0.109s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1455,"lbm_read_time_us":8010,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29062,"lbm_writes_lt_1ms":443,"mutex_wait_us":423,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:16:28.274452  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:28.314859  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.040s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18469,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.315368  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:28.326753  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.327310  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.458292  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.131s	user 0.115s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":9062,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27663,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:16:28.458858  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:28.510903  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.052s	user 0.032s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19273,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.511672  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:28.527329  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.015s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.527812  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.681979  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.154s	user 0.115s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":11274,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25712,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:28.682731  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:28.720582  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.721171  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.835072  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.114s	user 0.089s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487818,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1759,"lbm_read_time_us":7652,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22558,"lbm_writes_lt_1ms":343,"mutex_wait_us":390,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.835724  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:28.883068  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.047s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19616,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.883662  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:28.895782  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.896680  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushMRSOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:28.931169  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushMRSOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.034s	user 0.023s	sys 0.010s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1368,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2272,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:28.931996  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling LogGCOp(32419373687f44e2a60a121de8a30017): free 120100262 bytes of WAL
I20260812 06:16:28.932238  8716 log_reader.cc:385] T 32419373687f44e2a60a121de8a30017: removed 12 log segments from log reader
I20260812 06:16:28.932283  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000002 (ops 7-11)
I20260812 06:16:28.932313  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000003 (ops 12-16)
I20260812 06:16:28.932377  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000004 (ops 17-21)
I20260812 06:16:28.932407  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000005 (ops 22-26)
I20260812 06:16:28.932447  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000006 (ops 27-30)
I20260812 06:16:28.932505  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000007 (ops 31-35)
I20260812 06:16:28.932545  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000008 (ops 36-40)
I20260812 06:16:28.932583  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000009 (ops 41-44)
I20260812 06:16:28.932622  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000010 (ops 45-49)
I20260812 06:16:28.932662  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000011 (ops 50-54)
I20260812 06:16:28.932701  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000012 (ops 55-58)
I20260812 06:16:28.932739  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000013 (ops 59-63)
I20260812 06:16:28.959862  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: LogGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:28.960505  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017): 473 bytes on disk
I20260812 06:16:28.961193  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.961736  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=3.181125
I20260812 06:16:28.982321  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.020s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6985,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:28.983073  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling LogGCOp(32419373687f44e2a60a121de8a30017): free 12017983 bytes of WAL
I20260812 06:16:28.983340  8716 log_reader.cc:385] T 32419373687f44e2a60a121de8a30017: removed 1 log segments from log reader
I20260812 06:16:28.983393  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000014 (ops 64-68)
I20260812 06:16:28.985971  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: LogGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:28.986271  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:28.997311  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3773,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.997851  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:29.180931  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.183s	user 0.125s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6205,"lbm_read_time_us":14254,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35098,"lbm_writes_lt_1ms":643,"mutex_wait_us":2043,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:16:29.181824  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:29.239192  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.057s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24073,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.239655  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:29.250736  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.251406  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:29.406446  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.155s	user 0.103s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692756,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":5135,"dirs.run_cpu_time_us":1180,"dirs.run_wall_time_us":8628,"lbm_read_time_us":10987,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29694,"lbm_writes_lt_1ms":543,"mutex_wait_us":4860,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:16:29.407155  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=11.118625
I20260812 06:16:29.451619  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18388,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.452199  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:29.475656  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.023s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5081,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.476115  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:29.490834  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.491431  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:29.678753  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.187s	user 0.108s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692868,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":349,"lbm_read_time_us":11415,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29951,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:29.679489  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:29.731194  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.051s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23212,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.731760  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:29.885502  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.154s	user 0.093s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590227,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":314,"lbm_read_time_us":9513,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26745,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:16:29.886354  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:29.936729  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.050s	user 0.022s	sys 0.022s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20960,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.937269  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:29.953162  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5910,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.953779  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:30.133682  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.180s	user 0.137s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1326,"lbm_read_time_us":13730,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29309,"lbm_writes_lt_1ms":543,"mutex_wait_us":411,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:16:30.135142  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:30.180155  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19791,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.180693  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:30.194775  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.195261  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:30.326517  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.131s	user 0.115s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":9976,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26045,"lbm_writes_lt_1ms":443,"mutex_wait_us":93,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2000}
I20260812 06:16:30.327152  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=10.126437
I20260812 06:16:30.370575  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.043s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19831,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:30.371140  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:30.387852  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.388414  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushMRSOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:30.418532  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushMRSOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2022,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:30.419315  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling LogGCOp(32419373687f44e2a60a121de8a30017): free 116849514 bytes of WAL
I20260812 06:16:30.419581  8716 log_reader.cc:385] T 32419373687f44e2a60a121de8a30017: removed 12 log segments from log reader
I20260812 06:16:30.419647  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000015 (ops 69-73)
I20260812 06:16:30.419703  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000016 (ops 74-78)
I20260812 06:16:30.419761  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000017 (ops 79-82)
I20260812 06:16:30.419804  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000018 (ops 83-87)
I20260812 06:16:30.419845  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000019 (ops 88-92)
I20260812 06:16:30.419885  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000020 (ops 93-97)
I20260812 06:16:30.419924  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000021 (ops 98-102)
I20260812 06:16:30.419966  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000022 (ops 103-106)
I20260812 06:16:30.420006  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000023 (ops 107-111)
I20260812 06:16:30.420044  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000024 (ops 112-116)
I20260812 06:16:30.420084  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000025 (ops 117-120)
I20260812 06:16:30.420122  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000026 (ops 121-125)
I20260812 06:16:30.448359  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: LogGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:30.448931  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017): 471 bytes on disk
I20260812 06:16:30.449498  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.450163  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=4.173312
I20260812 06:16:30.466277  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":5456465,"delete_count":0,"lbm_write_time_us":6389,"lbm_writes_lt_1ms":136,"reinsert_count":0,"update_count":665}
I20260812 06:16:30.466811  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=1.196750
I20260812 06:16:30.476153  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":2684,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:16:30.476645  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:30.633582  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.156s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":910,"lbm_read_time_us":11287,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32214,"lbm_writes_lt_1ms":643,"mutex_wait_us":338,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19200,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:16:30.634400  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:30.690073  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.055s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20281,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.690737  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:30.706416  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.706975  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:30.865356  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.158s	user 0.115s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":940,"lbm_read_time_us":12341,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31032,"lbm_writes_lt_1ms":543,"mutex_wait_us":421,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:16:30.866024  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=11.118625
I20260812 06:16:30.896416  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.030s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13487,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:30.897230  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:30.913102  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5629,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.919458  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:31.062904  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.142s	user 0.095s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590341,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":11477,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23872,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:16:31.063802  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=11.118625
I20260812 06:16:31.109232  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.045s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16102,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:31.109791  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.129550  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.020s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.130189  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.141177  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.141825  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:31.330557  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.188s	user 0.135s	sys 0.050s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":176,"lbm_read_time_us":15217,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33526,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:16:31.331234  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:31.386462  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.055s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20323,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.387188  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.406688  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.019s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.407364  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:31.584201  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.177s	user 0.103s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":11556,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30288,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":430976,"update_count":2500}
I20260812 06:16:31.584726  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=14.095187
I20260812 06:16:31.650763  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.066s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22546,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.651388  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.668331  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.669024  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:31.861421  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.192s	user 0.131s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":747,"lbm_read_time_us":13096,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33346,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:16:31.862334  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=11.118625
I20260812 06:16:31.906973  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.044s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19682,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:31.907719  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.934332  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5619,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.934973  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:31.945604  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.946138  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushMRSOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:31.975271  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushMRSOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.029s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1354,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1746,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:31.975960  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:32.155867  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.180s	user 0.126s	sys 0.054s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692871,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":279,"lbm_read_time_us":12750,"lbm_reads_lt_1ms":565,"lbm_write_time_us":30652,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38272,"update_count":2500}
I20260812 06:16:32.156494  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling LogGCOp(32419373687f44e2a60a121de8a30017): free 128867663 bytes of WAL
I20260812 06:16:32.156786  8716 log_reader.cc:385] T 32419373687f44e2a60a121de8a30017: removed 13 log segments from log reader
I20260812 06:16:32.156862  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000027 (ops 126-130)
I20260812 06:16:32.156932  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000028 (ops 131-135)
I20260812 06:16:32.156978  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000029 (ops 136-140)
I20260812 06:16:32.157052  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000030 (ops 141-144)
I20260812 06:16:32.157114  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000031 (ops 145-149)
I20260812 06:16:32.157187  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000032 (ops 150-154)
I20260812 06:16:32.157227  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000033 (ops 155-158)
I20260812 06:16:32.157269  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000034 (ops 159-163)
I20260812 06:16:32.157308  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000035 (ops 164-168)
I20260812 06:16:32.157353  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000036 (ops 169-173)
I20260812 06:16:32.157425  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000037 (ops 174-178)
I20260812 06:16:32.157476  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000038 (ops 179-182)
I20260812 06:16:32.157521  8716 log.cc:1079] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/32419373687f44e2a60a121de8a30017/wal-000000039 (ops 183-187)
I20260812 06:16:32.187961  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: LogGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:32.188364  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017): 473 bytes on disk
I20260812 06:16:32.188773  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: UndoDeltaBlockGCOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.189297  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=15.087375
I20260812 06:16:32.234354  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.045s	user 0.036s	sys 0.005s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19651,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:32.235008  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:32.255618  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.020s	user 0.012s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:16:32.256214  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=2.188937
I20260812 06:16:32.266593  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3933,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:32.267082  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017): perf score=1.000000
I20260812 06:16:32.366534  8522 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.099s	user 1.853s	sys 0.152s
I20260812 06:16:32.463349  8522 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.096s	user 0.002s	sys 0.000s
I20260812 06:16:32.464046  8522 tablet_server.cc:179] TabletServer@127.8.82.129:0 shutting down...
I20260812 06:16:32.467073  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: MajorDeltaCompactionOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.200s	user 0.167s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":300,"lbm_read_time_us":14489,"lbm_reads_lt_1ms":669,"lbm_write_time_us":36984,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:32.468863  8821 maintenance_manager.cc:419] P 4b690e5096de45bd86dcd1f70690e716: Scheduling FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017): perf score=6.157687
I20260812 06:16:32.493052  8716 maintenance_manager.cc:643] P 4b690e5096de45bd86dcd1f70690e716: FlushDeltaMemStoresOp(32419373687f44e2a60a121de8a30017) complete. Timing: real 0.024s	user 0.015s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10151,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:32.493903  8522 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:32.494309  8522 tablet_replica.cc:333] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716: stopping tablet replica
I20260812 06:16:32.494644  8522 raft_consensus.cc:2243] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.495373  8522 raft_consensus.cc:2272] T 32419373687f44e2a60a121de8a30017 P 4b690e5096de45bd86dcd1f70690e716 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.512202  8522 tablet_server.cc:196] TabletServer@127.8.82.129:0 shutdown complete.
I20260812 06:16:32.524875  8522 master.cc:562] Master@127.8.82.190:42951 shutting down...
I20260812 06:16:32.529385  8522 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.529604  8522 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.529700  8522 tablet_replica.cc:333] T 00000000000000000000000000000000 P fa97d3e392624a8696f2efd419a3cb8f: stopping tablet replica
I20260812 06:16:32.542241  8522 master.cc:584] Master@127.8.82.190:42951 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5702 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:32.648752  8522 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.82.190:39237
I20260812 06:16:32.649217  8522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.651949  8882 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:16:32.651901  8879 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:16:32.651975  8522 server_base.cc:1061] running on GCE node
W20260812 06:16:32.652006  8880 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:16:32.652289  8522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.652331  8522 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:16:32.652348  8522 hybrid_clock.cc:648] HybridClock initialized: now 1786515392652348 us; error 0 us; skew 500 ppm
I20260812 06:16:32.653371  8522 webserver.cc:533] Webserver started at http://127.8.82.190:40623/ using document root <none> and password file <none>
I20260812 06:16:32.653528  8522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.653568  8522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.653625  8522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.654003  8522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/master-0-root/instance:
uuid: "a28b48a9e458420aa75a63921c86b146"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-tk9z"
I20260812 06:16:32.655714  8522 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:32.656935  8890 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:16:32.657284  8522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:32.657392  8522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/master-0-root
uuid: "a28b48a9e458420aa75a63921c86b146"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-tk9z"
I20260812 06:16:32.657502  8522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-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:16:32.664835  8522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.665302  8522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.670317  8522 rpc_server.cc:307] RPC server started. Bound to: 127.8.82.190:39237
I20260812 06:16:32.675177  8993 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.82.190:39237 every 8 connection(s)
I20260812 06:16:32.675671  8995 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:16:32.677642  8995 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146: Bootstrap starting.
I20260812 06:16:32.678526  8995 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:32.679733  8995 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146: No bootstrap required, opened a new log
I20260812 06:16:32.680219  8995 raft_consensus.cc:359] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER }
I20260812 06:16:32.680338  8995 raft_consensus.cc:385] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:32.680389  8995 raft_consensus.cc:740] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a28b48a9e458420aa75a63921c86b146, State: Initialized, Role: FOLLOWER
I20260812 06:16:32.680594  8995 consensus_queue.cc:260] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [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: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER }
I20260812 06:16:32.680709  8995 raft_consensus.cc:399] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:32.680758  8995 raft_consensus.cc:493] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:32.680822  8995 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:32.681574  8995 raft_consensus.cc:515] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER }
I20260812 06:16:32.681733  8995 leader_election.cc:304] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [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: a28b48a9e458420aa75a63921c86b146; no voters: 
I20260812 06:16:32.681979  8995 leader_election.cc:290] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:32.682122  9005 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:32.682430  9005 raft_consensus.cc:697] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 1 LEADER]: Becoming Leader. State: Replica: a28b48a9e458420aa75a63921c86b146, State: Running, Role: LEADER
I20260812 06:16:32.682523  8995 sys_catalog.cc:565] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:32.682578  9005 consensus_queue.cc:237] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [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: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER }
I20260812 06:16:32.683054  9009 sys_catalog.cc:455] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a28b48a9e458420aa75a63921c86b146" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER } }
I20260812 06:16:32.683099  9011 sys_catalog.cc:455] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a28b48a9e458420aa75a63921c86b146. Latest consensus state: current_term: 1 leader_uuid: "a28b48a9e458420aa75a63921c86b146" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a28b48a9e458420aa75a63921c86b146" member_type: VOTER } }
I20260812 06:16:32.683218  9009 sys_catalog.cc:458] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.683234  9011 sys_catalog.cc:458] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.683815  9020 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:32.684531  9020 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:32.684804  8522 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:32.686596  9020 catalog_manager.cc:1383] Generated new cluster ID: a7ecd4af8722435c8c2ae17c748387a1
I20260812 06:16:32.686669  9020 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:32.697103  9020 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:32.697747  9020 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:32.712805  9020 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146: Generated new TSK 0
I20260812 06:16:32.713011  9020 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:32.717764  8522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.720263  9041 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:16:32.720417  8522 server_base.cc:1061] running on GCE node
W20260812 06:16:32.720342  9039 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:16:32.720314  9048 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:16:32.720781  8522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.720831  8522 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:16:32.720849  8522 hybrid_clock.cc:648] HybridClock initialized: now 1786515392720848 us; error 0 us; skew 500 ppm
I20260812 06:16:32.721809  8522 webserver.cc:533] Webserver started at http://127.8.82.129:39023/ using document root <none> and password file <none>
I20260812 06:16:32.722004  8522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.722086  8522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.722193  8522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.722675  8522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/instance:
uuid: "35a601ba9b8449d88128a965f0018ed7"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-tk9z"
I20260812 06:16:32.724257  8522 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:32.725198  9053 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:16:32.725464  8522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:32.725558  8522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root
uuid: "35a601ba9b8449d88128a965f0018ed7"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-tk9z"
I20260812 06:16:32.725653  8522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-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:16:32.734521  8522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.734894  8522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.735206  8522 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:32.735687  8522 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:32.735749  8522 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.735812  8522 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:32.735848  8522 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.740278  8522 rpc_server.cc:307] RPC server started. Bound to: 127.8.82.129:39767
I20260812 06:16:32.740815  9178 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.82.129:39767 every 8 connection(s)
I20260812 06:16:32.749245  9180 heartbeater.cc:344] Connected to a master server at 127.8.82.190:39237
I20260812 06:16:32.749390  9180 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:32.749645  9180 heartbeater.cc:507] Master 127.8.82.190:39237 requested a full tablet report, sending...
I20260812 06:16:32.750521  8930 ts_manager.cc:194] Registered new tserver with Master: 35a601ba9b8449d88128a965f0018ed7 (127.8.82.129:39767)
I20260812 06:16:32.751035  8522 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010025788s
I20260812 06:16:32.751433  8930 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51110
I20260812 06:16:32.759429  8930 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51116:
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:16:32.770646  9100 tablet_service.cc:1511] Processing CreateTablet for tablet 07b3a64b5aeb46668a9d85afceaf6d3f (DEFAULT_TABLE table=heavy-update-compaction-test [id=9bfb4f7cda4d4be0adcd698f49a4c533]), partition=
I20260812 06:16:32.770988  9100 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 07b3a64b5aeb46668a9d85afceaf6d3f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:32.773252  9201 tablet_bootstrap.cc:492] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Bootstrap starting.
I20260812 06:16:32.774276  9201 tablet_bootstrap.cc:654] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:32.775908  9201 tablet_bootstrap.cc:492] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: No bootstrap required, opened a new log
I20260812 06:16:32.776003  9201 ts_tablet_manager.cc:1403] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:32.776423  9201 raft_consensus.cc:359] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35a601ba9b8449d88128a965f0018ed7" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 39767 } }
I20260812 06:16:32.776525  9201 raft_consensus.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:32.776548  9201 raft_consensus.cc:740] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 35a601ba9b8449d88128a965f0018ed7, State: Initialized, Role: FOLLOWER
I20260812 06:16:32.776710  9201 consensus_queue.cc:260] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [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: "35a601ba9b8449d88128a965f0018ed7" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 39767 } }
I20260812 06:16:32.776806  9201 raft_consensus.cc:399] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:32.776832  9201 raft_consensus.cc:493] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:32.776870  9201 raft_consensus.cc:3060] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:32.777689  9201 raft_consensus.cc:515] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35a601ba9b8449d88128a965f0018ed7" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 39767 } }
I20260812 06:16:32.777827  9201 leader_election.cc:304] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [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: 35a601ba9b8449d88128a965f0018ed7; no voters: 
I20260812 06:16:32.778002  9201 leader_election.cc:290] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:32.778162  9203 raft_consensus.cc:2804] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:32.778431  9201 ts_tablet_manager.cc:1434] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:32.778430  9180 heartbeater.cc:499] Master 127.8.82.190:39237 was elected leader, sending a full tablet report...
I20260812 06:16:32.778481  9203 raft_consensus.cc:697] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 1 LEADER]: Becoming Leader. State: Replica: 35a601ba9b8449d88128a965f0018ed7, State: Running, Role: LEADER
I20260812 06:16:32.778892  9203 consensus_queue.cc:237] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [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: "35a601ba9b8449d88128a965f0018ed7" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 39767 } }
I20260812 06:16:32.780392  8930 catalog_manager.cc:5719] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 35a601ba9b8449d88128a965f0018ed7 (127.8.82.129). New cstate: current_term: 1 leader_uuid: "35a601ba9b8449d88128a965f0018ed7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35a601ba9b8449d88128a965f0018ed7" member_type: VOTER last_known_addr { host: "127.8.82.129" port: 39767 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:32.838709  8522 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:16:32.991633  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=19.054940
I20260812 06:16:33.148550  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.157s	user 0.111s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":777,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38419,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:33.149528  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): free 20743880 bytes of WAL
I20260812 06:16:33.149799  9064 log_reader.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f: removed 2 log segments from log reader
I20260812 06:16:33.149855  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000001 (ops 1-6)
I20260812 06:16:33.149916  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000002 (ops 7-11)
I20260812 06:16:33.156028  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:33.156561  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:33.174249  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.174805  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): 16411393 bytes on disk
I20260812 06:16:33.175446  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:16:33.175951  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:33.327131  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.151s	user 0.107s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":511,"lbm_read_time_us":9437,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24349,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":322,"threads_started":5,"update_count":2000}
I20260812 06:16:33.327860  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=11.118625
I20260812 06:16:33.374195  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.046s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":20287,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:33.374773  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:33.408795  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.034s	user 0.009s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.409379  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:33.421689  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.422180  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:33.619163  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.197s	user 0.133s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":256,"lbm_read_time_us":12398,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29582,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:16:33.619764  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:33.676844  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.057s	user 0.036s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23403,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.677328  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:33.689042  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.689720  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:33.906558  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.217s	user 0.153s	sys 0.046s 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":889,"lbm_read_time_us":11537,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31293,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":533760,"update_count":2500}
I20260812 06:16:33.907274  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:33.973851  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.066s	user 0.046s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.974325  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:33.986209  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.986956  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:34.159747  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.173s	user 0.132s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":10318,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33905,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:16:34.160439  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=11.118625
I20260812 06:16:34.200786  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.040s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16196,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:34.201557  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:34.217772  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.218225  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:34.228053  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.228498  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:34.403437  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.175s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":999,"lbm_read_time_us":10971,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34655,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2500}
I20260812 06:16:34.403990  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:34.463176  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.059s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23458,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.463650  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:34.474596  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.475314  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:34.502103  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.027s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1181,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1336,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:34.502884  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): free 120553322 bytes of WAL
I20260812 06:16:34.503146  9064 log_reader.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f: removed 12 log segments from log reader
I20260812 06:16:34.503217  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000003 (ops 12-16)
I20260812 06:16:34.503273  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000004 (ops 17-21)
I20260812 06:16:34.503330  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000005 (ops 22-26)
I20260812 06:16:34.503372  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000006 (ops 27-31)
I20260812 06:16:34.503410  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000007 (ops 32-36)
I20260812 06:16:34.503448  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000008 (ops 37-40)
I20260812 06:16:34.503484  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000009 (ops 41-45)
I20260812 06:16:34.503522  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000010 (ops 46-50)
I20260812 06:16:34.503558  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000011 (ops 51-55)
I20260812 06:16:34.503595  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000012 (ops 56-60)
I20260812 06:16:34.503633  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000013 (ops 61-64)
I20260812 06:16:34.503670  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000014 (ops 65-69)
I20260812 06:16:34.530652  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:34.531062  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=3.181125
I20260812 06:16:34.543002  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:34.543493  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): 462 bytes on disk
I20260812 06:16:34.543913  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) 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:16:34.544492  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:34.566056  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.566658  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:34.807701  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.241s	user 0.151s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":622,"lbm_read_time_us":17271,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39586,"lbm_writes_lt_1ms":743,"mutex_wait_us":288,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:16:34.808499  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=18.063937
I20260812 06:16:34.874850  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.066s	user 0.025s	sys 0.039s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28031,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:34.875607  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:34.892092  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.892581  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:35.114858  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.222s	user 0.147s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":14676,"lbm_reads_lt_1ms":668,"lbm_write_time_us":35564,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25600,"update_count":3000}
I20260812 06:16:35.115720  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=18.063937
I20260812 06:16:35.187162  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.071s	user 0.036s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27922,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:35.187652  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:35.199988  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.200732  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:35.397271  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.196s	user 0.116s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":13894,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32442,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":3000}
I20260812 06:16:35.398022  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:35.455804  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.058s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24902,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.456606  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:35.481192  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.024s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.481729  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:35.492942  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.493496  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:35.709614  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.216s	user 0.163s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1299,"lbm_read_time_us":15624,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35324,"lbm_writes_lt_1ms":643,"mutex_wait_us":600,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:16:35.710495  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:35.761293  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.050s	user 0.021s	sys 0.026s Metrics: {"bytes_written":16491949,"delete_count":0,"lbm_write_time_us":21972,"lbm_writes_lt_1ms":405,"reinsert_count":0,"update_count":2010}
I20260812 06:16:35.761838  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:35.781375  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.019s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":101,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":490}
I20260812 06:16:35.781870  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:35.793514  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.793996  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:36.000449  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.206s	user 0.151s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877216,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":346,"lbm_read_time_us":13697,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34662,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":50304,"update_count":3000}
I20260812 06:16:36.001224  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:36.043169  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.042s	user 0.037s	sys 0.003s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18182,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.043699  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.066740  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.023s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:16:36.067269  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:36.121531  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.054s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":354,"dirs.run_wall_time_us":1762,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1809,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1920}
I20260812 06:16:36.122267  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): free 120553387 bytes of WAL
I20260812 06:16:36.122562  9064 log_reader.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f: removed 12 log segments from log reader
I20260812 06:16:36.122624  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000015 (ops 70-74)
I20260812 06:16:36.122663  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000016 (ops 75-79)
I20260812 06:16:36.122700  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000017 (ops 80-84)
I20260812 06:16:36.122733  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000018 (ops 85-89)
I20260812 06:16:36.122763  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000019 (ops 90-94)
I20260812 06:16:36.122790  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000020 (ops 95-98)
I20260812 06:16:36.122817  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000021 (ops 99-103)
I20260812 06:16:36.122851  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000022 (ops 104-108)
I20260812 06:16:36.122884  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000023 (ops 109-112)
I20260812 06:16:36.122922  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000024 (ops 113-117)
I20260812 06:16:36.122952  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000025 (ops 118-122)
I20260812 06:16:36.122975  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000026 (ops 123-127)
I20260812 06:16:36.154644  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.032s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:16:36.155047  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=6.157687
I20260812 06:16:36.181123  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.026s	user 0.005s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9153,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:36.181684  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): free 8767191 bytes of WAL
I20260812 06:16:36.181910  9064 log_reader.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f: removed 1 log segments from log reader
I20260812 06:16:36.181955  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000027 (ops 128-132)
I20260812 06:16:36.183961  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:36.184319  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.195648  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.196210  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): 493 bytes on disk
I20260812 06:16:36.196759  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:16:36.197372  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:36.450091  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.253s	user 0.171s	sys 0.079s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082160,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2188,"lbm_read_time_us":18876,"lbm_reads_lt_1ms":874,"lbm_write_time_us":46368,"lbm_writes_lt_1ms":843,"mutex_wait_us":1601,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:16:36.450927  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=19.056125
I20260812 06:16:36.512038  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.061s	user 0.041s	sys 0.018s Metrics: {"bytes_written":20922554,"delete_count":0,"lbm_write_time_us":27301,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:16:36.512617  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.534109  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.021s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4977,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:36.534624  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.545363  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.546015  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:36.738900  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.193s	user 0.163s	sys 0.028s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979618,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1891,"lbm_read_time_us":12725,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39563,"lbm_writes_lt_1ms":743,"mutex_wait_us":1198,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":3500}
I20260812 06:16:36.739689  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:36.792052  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.052s	user 0.015s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21154,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.792784  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.811972  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.812465  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:36.823482  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.824043  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:36.999068  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.175s	user 0.157s	sys 0.016s 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":2015,"lbm_read_time_us":13262,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34053,"lbm_writes_lt_1ms":643,"mutex_wait_us":1340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":3000}
I20260812 06:16:36.999866  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:37.051991  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.052s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22071,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.052768  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:37.080922  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.028s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.081398  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:37.092283  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.092788  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:37.266428  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.173s	user 0.140s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":445,"lbm_read_time_us":14000,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35602,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":31872,"update_count":3000}
I20260812 06:16:37.267150  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:37.313089  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20438,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.314251  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:37.325006  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.325505  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:37.492311  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.167s	user 0.116s	sys 0.040s 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":230,"lbm_read_time_us":12532,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28078,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:16:37.493217  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=14.095187
I20260812 06:16:37.558677  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.065s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23963,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.559315  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:37.572273  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.572885  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:37.607566  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushMRSOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1431,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2393,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:37.608255  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): free 132571585 bytes of WAL
I20260812 06:16:37.608505  9064 log_reader.cc:385] T 07b3a64b5aeb46668a9d85afceaf6d3f: removed 13 log segments from log reader
I20260812 06:16:37.608551  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000028 (ops 133-136)
I20260812 06:16:37.608582  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000029 (ops 137-141)
I20260812 06:16:37.608644  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000030 (ops 142-146)
I20260812 06:16:37.608688  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000031 (ops 147-150)
I20260812 06:16:37.608728  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000032 (ops 151-155)
I20260812 06:16:37.608772  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000033 (ops 156-160)
I20260812 06:16:37.608834  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000034 (ops 161-165)
I20260812 06:16:37.608882  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000035 (ops 166-170)
I20260812 06:16:37.608907  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000036 (ops 171-175)
I20260812 06:16:37.608947  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000037 (ops 176-180)
I20260812 06:16:37.608985  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000038 (ops 181-185)
I20260812 06:16:37.609025  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000039 (ops 186-190)
I20260812 06:16:37.609064  9064 log.cc:1079] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: Deleting log segment in path: /tmp/dist-test-tasktPNrfX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386921911-8522-0/minicluster-data/ts-0-root/wals/07b3a64b5aeb46668a9d85afceaf6d3f/wal-000000040 (ops 191-195)
I20260812 06:16:37.638809  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: LogGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:37.639248  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f): 482 bytes on disk
I20260812 06:16:37.639787  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: UndoDeltaBlockGCOp(07b3a64b5aeb46668a9d85afceaf6d3f) 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:16:37.640360  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=3.181125
I20260812 06:16:37.654573  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4867,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:37.655162  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=2.188937
I20260812 06:16:37.668804  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: FlushDeltaMemStoresOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.669425  9181 maintenance_manager.cc:419] P 35a601ba9b8449d88128a965f0018ed7: Scheduling MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f): perf score=1.000000
I20260812 06:16:37.760489  8522 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.922s	user 1.839s	sys 0.180s
I20260812 06:16:37.857865  8522 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.001s	sys 0.000s
I20260812 06:16:37.858587  8522 tablet_server.cc:179] TabletServer@127.8.82.129:0 shutting down...
I20260812 06:16:37.881095  9064 maintenance_manager.cc:643] P 35a601ba9b8449d88128a965f0018ed7: MajorDeltaCompactionOp(07b3a64b5aeb46668a9d85afceaf6d3f) complete. Timing: real 0.211s	user 0.126s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":444,"lbm_read_time_us":16071,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33257,"lbm_writes_lt_1ms":743,"mutex_wait_us":142,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":27776,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:16:37.882464  8522 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:37.882886  8522 tablet_replica.cc:333] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7: stopping tablet replica
I20260812 06:16:37.883080  8522 raft_consensus.cc:2243] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:37.883316  8522 raft_consensus.cc:2272] T 07b3a64b5aeb46668a9d85afceaf6d3f P 35a601ba9b8449d88128a965f0018ed7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:37.899312  8522 tablet_server.cc:196] TabletServer@127.8.82.129:0 shutdown complete.
I20260812 06:16:37.939867  8522 master.cc:562] Master@127.8.82.190:39237 shutting down...
I20260812 06:16:37.943466  8522 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:37.943691  8522 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:37.943785  8522 tablet_replica.cc:333] T 00000000000000000000000000000000 P a28b48a9e458420aa75a63921c86b146: stopping tablet replica
I20260812 06:16:37.956465  8522 master.cc:584] Master@127.8.82.190:39237 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5407 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11111 ms total)

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