[==========] 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:18:09.684089 28965 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.73.126:46435
I20260812 06:18:09.685217 28965 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:18:09.685988 28965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.693552 28971 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:18:09.693696 28965 server_base.cc:1061] running on GCE node
W20260812 06:18:09.693905 28973 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:18:09.693926 28970 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:18:09.694723 28965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.694826 28965 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:18:09.694856 28965 hybrid_clock.cc:648] HybridClock initialized: now 1786515489694854 us; error 0 us; skew 500 ppm
I20260812 06:18:09.697290 28965 webserver.cc:533] Webserver started at http://127.28.73.126:36611/ using document root <none> and password file <none>
I20260812 06:18:09.698057 28965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.698139 28965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.698378 28965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.700341 28965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/master-0-root/instance:
uuid: "5073512762fd4fa78a841cf1f62cab68"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-9zdj"
I20260812 06:18:09.704857 28965 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.002s	sys 0.004s
I20260812 06:18:09.707715 28978 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:18:09.709126 28965 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:09.709283 28965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/master-0-root
uuid: "5073512762fd4fa78a841cf1f62cab68"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-9zdj"
I20260812 06:18:09.709403 28965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-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:18:09.729007 28965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.729874 28965 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:18:09.730051 28965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.739709 29040 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.73.126:46435 every 8 connection(s)
I20260812 06:18:09.739712 28965 rpc_server.cc:307] RPC server started. Bound to: 127.28.73.126:46435
I20260812 06:18:09.742415 29041 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:18:09.748711 29041 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: Bootstrap starting.
I20260812 06:18:09.751488 29041 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.752593 29041 log.cc:826] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:09.754853 29041 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: No bootstrap required, opened a new log
I20260812 06:18:09.758087 29041 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER }
I20260812 06:18:09.758315 29041 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.758419 29041 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5073512762fd4fa78a841cf1f62cab68, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.759217 29041 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [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: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER }
I20260812 06:18:09.759387 29041 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.759508 29041 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.759667 29041 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.760614 29041 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER }
I20260812 06:18:09.761126 29041 leader_election.cc:304] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [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: 5073512762fd4fa78a841cf1f62cab68; no voters: 
I20260812 06:18:09.761508 29041 leader_election.cc:290] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.761770 29044 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.762068 29044 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 1 LEADER]: Becoming Leader. State: Replica: 5073512762fd4fa78a841cf1f62cab68, State: Running, Role: LEADER
I20260812 06:18:09.762632 29044 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [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: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER }
I20260812 06:18:09.762818 29041 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:09.765177 29046 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5073512762fd4fa78a841cf1f62cab68. Latest consensus state: current_term: 1 leader_uuid: "5073512762fd4fa78a841cf1f62cab68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER } }
I20260812 06:18:09.765312 29046 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:09.765553 29045 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5073512762fd4fa78a841cf1f62cab68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5073512762fd4fa78a841cf1f62cab68" member_type: VOTER } }
I20260812 06:18:09.765550 28965 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:09.765673 29045 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [sys.catalog]: This master's current role is: LEADER
W20260812 06:18:09.767788 29060 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:09.767869 29060 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:09.767967 29061 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:09.768765 29061 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:09.774586 29061 catalog_manager.cc:1383] Generated new cluster ID: 62c5a33a5b7e4664b04b4ea43a3bd5fb
I20260812 06:18:09.774690 29061 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:09.784704 29061 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:09.786145 29061 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:09.797361 29061 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: Generated new TSK 0
I20260812 06:18:09.798333 29061 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:09.830883 28965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.834152 29065 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:18:09.834364 29066 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:18:09.834518 28965 server_base.cc:1061] running on GCE node
W20260812 06:18:09.834173 29068 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:18:09.834957 28965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.835037 28965 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:18:09.835067 28965 hybrid_clock.cc:648] HybridClock initialized: now 1786515489835066 us; error 0 us; skew 500 ppm
I20260812 06:18:09.836123 28965 webserver.cc:533] Webserver started at http://127.28.73.65:44271/ using document root <none> and password file <none>
I20260812 06:18:09.836373 28965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.836462 28965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.836556 28965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.837031 28965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/instance:
uuid: "9345a8c63a214c879aa91012bee90286"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-9zdj"
I20260812 06:18:09.838924 28965 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:09.840092 29075 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:18:09.840382 28965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:09.840468 28965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root
uuid: "9345a8c63a214c879aa91012bee90286"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-9zdj"
I20260812 06:18:09.840588 28965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-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:18:09.858386 28965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.858970 28965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.859592 28965 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:09.860695 28965 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:09.860816 28965 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.860901 28965 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:09.860952 28965 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.869767 28965 rpc_server.cc:307] RPC server started. Bound to: 127.28.73.65:34639
I20260812 06:18:09.869783 29146 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.73.65:34639 every 8 connection(s)
I20260812 06:18:09.881927 29147 heartbeater.cc:344] Connected to a master server at 127.28.73.126:46435
I20260812 06:18:09.882228 29147 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:09.882807 29147 heartbeater.cc:507] Master 127.28.73.126:46435 requested a full tablet report, sending...
I20260812 06:18:09.884692 28997 ts_manager.cc:194] Registered new tserver with Master: 9345a8c63a214c879aa91012bee90286 (127.28.73.65:34639)
I20260812 06:18:09.885300 28965 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01476842s
I20260812 06:18:09.886165 28997 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40758
I20260812 06:18:09.897033 28997 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40760:
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:18:09.914305 29107 tablet_service.cc:1511] Processing CreateTablet for tablet 764dde7b33cc437998d9f7db60b4e2d8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=16825bbd6e4e4d088265f402aa327511]), partition=
I20260812 06:18:09.914867 29107 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 764dde7b33cc437998d9f7db60b4e2d8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:09.917735 29163 tablet_bootstrap.cc:492] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Bootstrap starting.
I20260812 06:18:09.919318 29163 tablet_bootstrap.cc:654] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.920995 29163 tablet_bootstrap.cc:492] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: No bootstrap required, opened a new log
I20260812 06:18:09.921203 29163 ts_tablet_manager.cc:1403] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:18:09.922009 29163 raft_consensus.cc:359] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9345a8c63a214c879aa91012bee90286" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 34639 } }
I20260812 06:18:09.922161 29163 raft_consensus.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.922230 29163 raft_consensus.cc:740] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9345a8c63a214c879aa91012bee90286, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.922402 29163 consensus_queue.cc:260] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [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: "9345a8c63a214c879aa91012bee90286" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 34639 } }
I20260812 06:18:09.922511 29163 raft_consensus.cc:399] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.922565 29163 raft_consensus.cc:493] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.922621 29163 raft_consensus.cc:3060] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.923756 29163 raft_consensus.cc:515] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9345a8c63a214c879aa91012bee90286" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 34639 } }
I20260812 06:18:09.923934 29163 leader_election.cc:304] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [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: 9345a8c63a214c879aa91012bee90286; no voters: 
I20260812 06:18:09.924207 29163 leader_election.cc:290] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.924427 29167 raft_consensus.cc:2804] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.924626 29163 ts_tablet_manager.cc:1434] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:09.924847 29147 heartbeater.cc:499] Master 127.28.73.126:46435 was elected leader, sending a full tablet report...
I20260812 06:18:09.924681 29167 raft_consensus.cc:697] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 1 LEADER]: Becoming Leader. State: Replica: 9345a8c63a214c879aa91012bee90286, State: Running, Role: LEADER
I20260812 06:18:09.925495 29167 consensus_queue.cc:237] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [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: "9345a8c63a214c879aa91012bee90286" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 34639 } }
I20260812 06:18:09.928990 28997 catalog_manager.cc:5719] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9345a8c63a214c879aa91012bee90286 (127.28.73.65). New cstate: current_term: 1 leader_uuid: "9345a8c63a214c879aa91012bee90286" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9345a8c63a214c879aa91012bee90286" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 34639 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:10.003872 28965 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.025s	sys 0.008s
I20260812 06:18:10.121248 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=15.086190
I20260812 06:18:10.286180 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.164s	user 0.112s	sys 0.051s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":282,"delete_count":0,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":3673,"drs_written":1,"lbm_read_time_us":133,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37781,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":150,"threads_started":1,"update_count":1050}
I20260812 06:18:10.287529 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling LogGCOp(764dde7b33cc437998d9f7db60b4e2d8): free 8725963 bytes of WAL
I20260812 06:18:10.287863 29081 log_reader.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8: removed 1 log segments from log reader
I20260812 06:18:10.287946 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000001 (ops 1-6)
I20260812 06:18:10.290186 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: LogGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:10.290632 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8): 12308958 bytes on disk
I20260812 06:18:10.291388 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:18:10.292091 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:10.311256 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.311856 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:10.440891 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.129s	user 0.095s	sys 0.021s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1143,"lbm_read_time_us":6380,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20353,"lbm_writes_lt_1ms":343,"mutex_wait_us":158,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13056,"thread_start_us":386,"threads_started":5,"update_count":1500}
I20260812 06:18:10.441648 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:10.494504 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.053s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21691,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.495091 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:10.511224 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.016s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.511837 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:10.645897 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.134s	user 0.114s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":9382,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24115,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:18:10.646602 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:10.703495 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.057s	user 0.032s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18039,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.704154 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:10.717085 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.013s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.717927 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:10.875212 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.157s	user 0.096s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":13058,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23690,"lbm_writes_lt_1ms":443,"mutex_wait_us":449,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:18:10.875793 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:10.926321 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.050s	user 0.016s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21356,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.926873 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:10.939272 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.939843 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:11.072763 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.133s	user 0.104s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":9943,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23855,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32256,"update_count":2000}
I20260812 06:18:11.073372 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:11.122417 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.049s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.122944 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:11.134230 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.134876 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:11.280009 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.145s	user 0.119s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":766,"lbm_read_time_us":10161,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28332,"lbm_writes_lt_1ms":443,"mutex_wait_us":352,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:18:11.280635 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:11.341544 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.061s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17767,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.342281 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:11.353472 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.354086 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:11.507164 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.153s	user 0.112s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":11376,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25244,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.507951 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:11.554378 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.046s	user 0.015s	sys 0.025s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17213,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.554949 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:11.567562 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.568148 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:11.701484 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.133s	user 0.121s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":11270,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23168,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:18:11.702286 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:11.747957 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.045s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16950,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.748723 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:11.762459 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.763041 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:11.801774 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.039s	user 0.038s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1587,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1831,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:11.802799 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling LogGCOp(764dde7b33cc437998d9f7db60b4e2d8): free 132571242 bytes of WAL
I20260812 06:18:11.803117 29081 log_reader.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8: removed 13 log segments from log reader
I20260812 06:18:11.803184 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000002 (ops 7-11)
I20260812 06:18:11.803256 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000003 (ops 12-16)
I20260812 06:18:11.803321 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000004 (ops 17-21)
I20260812 06:18:11.803392 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000005 (ops 22-26)
I20260812 06:18:11.803439 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000006 (ops 27-31)
I20260812 06:18:11.803489 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000007 (ops 32-36)
I20260812 06:18:11.803540 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000008 (ops 37-40)
I20260812 06:18:11.803587 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000009 (ops 41-45)
I20260812 06:18:11.803637 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000010 (ops 46-50)
I20260812 06:18:11.803682 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000011 (ops 51-55)
I20260812 06:18:11.803730 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000012 (ops 56-60)
I20260812 06:18:11.803776 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000013 (ops 61-64)
I20260812 06:18:11.803820 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000014 (ops 65-69)
I20260812 06:18:11.836820 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: LogGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:11.837375 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=5.165500
I20260812 06:18:11.863965 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.026s	user 0.015s	sys 0.011s Metrics: {"bytes_written":7302545,"delete_count":0,"lbm_write_time_us":10531,"lbm_writes_lt_1ms":181,"reinsert_count":0,"update_count":890}
I20260812 06:18:11.864854 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8): 483 bytes on disk
I20260812 06:18:11.865572 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.866428 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:12.056867 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.190s	user 0.122s	sys 0.055s Metrics: {"cfile_cache_miss":611,"cfile_cache_miss_bytes":27933723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2247,"lbm_read_time_us":14258,"lbm_reads_lt_1ms":647,"lbm_write_time_us":34712,"lbm_writes_lt_1ms":621,"mutex_wait_us":1566,"peak_mem_usage":72558934,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":86,"threads_started":1,"update_count":2890}
I20260812 06:18:12.057485 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=15.087375
I20260812 06:18:12.107547 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.050s	user 0.028s	sys 0.020s Metrics: {"bytes_written":17312440,"delete_count":0,"lbm_write_time_us":22505,"lbm_writes_lt_1ms":425,"reinsert_count":0,"update_count":2110}
I20260812 06:18:12.108183 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:12.124579 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.125317 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:12.298943 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.173s	user 0.118s	sys 0.045s Metrics: {"cfile_cache_miss":554,"cfile_cache_miss_bytes":25636262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":10783,"lbm_reads_lt_1ms":594,"lbm_write_time_us":36135,"lbm_writes_lt_1ms":565,"mutex_wait_us":120,"peak_mem_usage":65059054,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2610}
I20260812 06:18:12.299806 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=11.118625
I20260812 06:18:12.335031 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.035s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15705,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:12.335680 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:12.352656 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6462,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.353183 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:12.510334 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.157s	user 0.117s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":11178,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27799,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:18:12.511745 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:12.559868 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.048s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15608,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.560595 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:12.578359 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.579033 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:12.737552 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.158s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":13206,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23467,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:12.738214 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:12.796452 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.058s	user 0.035s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21479,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.797082 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:12.813761 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.016s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6057,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.814575 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:12.989812 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.175s	user 0.127s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":11505,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32056,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34560,"update_count":2000}
I20260812 06:18:12.990573 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=10.126437
I20260812 06:18:13.048878 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.058s	user 0.025s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20000,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.049671 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:13.069979 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.020s	user 0.011s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.070685 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:13.255779 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.185s	user 0.155s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":14719,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34000,"lbm_writes_lt_1ms":443,"mutex_wait_us":351,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:18:13.256587 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=14.095187
I20260812 06:18:13.305498 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22259,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.306185 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:13.320940 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.321542 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:13.350139 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.028s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1512,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1706,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:13.350961 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling LogGCOp(764dde7b33cc437998d9f7db60b4e2d8): free 112239375 bytes of WAL
I20260812 06:18:13.351302 29081 log_reader.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8: removed 11 log segments from log reader
I20260812 06:18:13.351349 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000015 (ops 70-74)
I20260812 06:18:13.351387 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000016 (ops 75-79)
I20260812 06:18:13.351449 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000017 (ops 80-84)
I20260812 06:18:13.351482 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000018 (ops 85-89)
I20260812 06:18:13.351518 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000019 (ops 90-94)
I20260812 06:18:13.351559 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000020 (ops 95-99)
I20260812 06:18:13.351600 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000021 (ops 100-104)
I20260812 06:18:13.351637 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000022 (ops 105-109)
I20260812 06:18:13.351676 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000023 (ops 110-114)
I20260812 06:18:13.351713 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000024 (ops 115-118)
I20260812 06:18:13.351751 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000025 (ops 119-123)
I20260812 06:18:13.379570 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: LogGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:13.380110 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=5.165500
I20260812 06:18:13.397774 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.017s	user 0.010s	sys 0.008s Metrics: {"bytes_written":6933327,"delete_count":0,"lbm_write_time_us":7311,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:18:13.398286 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling LogGCOp(764dde7b33cc437998d9f7db60b4e2d8): free 12017932 bytes of WAL
I20260812 06:18:13.398514 29081 log_reader.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8: removed 1 log segments from log reader
I20260812 06:18:13.398559 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000026 (ops 124-128)
I20260812 06:18:13.401361 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: LogGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:13.401898 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:13.407903 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1271927,"delete_count":0,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:18:13.408408 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8): 447 bytes on disk
I20260812 06:18:13.408856 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.409368 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:13.619663 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.210s	user 0.155s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938713,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":953,"lbm_read_time_us":16627,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40550,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:18:13.624791 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=14.095187
I20260812 06:18:13.672041 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20558,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.672763 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:13.703510 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.030s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.704087 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:13.720438 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.721087 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:13.912667 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.191s	user 0.168s	sys 0.020s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836254,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":263,"lbm_read_time_us":12815,"lbm_reads_lt_1ms":673,"lbm_write_time_us":41927,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":3000}
I20260812 06:18:13.913216 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=14.095187
I20260812 06:18:13.957224 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.044s	user 0.026s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19071,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.957965 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:14.089846 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.132s	user 0.090s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":938,"lbm_read_time_us":8505,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26988,"lbm_writes_lt_1ms":443,"mutex_wait_us":391,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.090606 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=11.118625
I20260812 06:18:14.136583 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.046s	user 0.007s	sys 0.036s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14720,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:14.137282 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:14.154714 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5105,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.155267 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:14.308947 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.153s	user 0.098s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":862,"lbm_read_time_us":9459,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24176,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:14.309533 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=14.095187
I20260812 06:18:14.362334 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.053s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21625,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.362964 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:14.375572 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.376134 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:14.572626 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.196s	user 0.107s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":12585,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33499,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:14.573393 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=14.095187
I20260812 06:18:14.627724 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.054s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23186,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.628320 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:14.640399 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.640973 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:14.813344 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.172s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":417,"lbm_read_time_us":11129,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37042,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:18:14.814296 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=11.118625
I20260812 06:18:14.855193 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.041s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17436,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:14.855955 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:14.873097 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.017s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5345,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.873757 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:14.928639 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushMRSOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.055s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1626,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2318,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:14.929690 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling LogGCOp(764dde7b33cc437998d9f7db60b4e2d8): free 120553643 bytes of WAL
I20260812 06:18:14.930020 29081 log_reader.cc:385] T 764dde7b33cc437998d9f7db60b4e2d8: removed 12 log segments from log reader
I20260812 06:18:14.930102 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000027 (ops 129-133)
I20260812 06:18:14.930164 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000028 (ops 134-138)
I20260812 06:18:14.930204 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000029 (ops 139-142)
I20260812 06:18:14.930238 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000030 (ops 143-147)
I20260812 06:18:14.930279 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000031 (ops 148-152)
I20260812 06:18:14.930315 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000032 (ops 153-157)
I20260812 06:18:14.930342 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000033 (ops 158-162)
I20260812 06:18:14.930375 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000034 (ops 163-167)
I20260812 06:18:14.930441 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000035 (ops 168-172)
I20260812 06:18:14.930481 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000036 (ops 173-177)
I20260812 06:18:14.930522 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000037 (ops 178-182)
I20260812 06:18:14.930560 29081 log.cc:1079] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/764dde7b33cc437998d9f7db60b4e2d8/wal-000000038 (ops 183-186)
I20260812 06:18:14.960459 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: LogGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:14.960994 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=7.149875
I20260812 06:18:14.988389 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11825,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:14.988891 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=2.188937
I20260812 06:18:15.016234 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.027s	user 0.001s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5561,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.016940 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=1.000000
I20260812 06:18:15.252182 28965 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.248s	user 1.932s	sys 0.127s
I20260812 06:18:15.255376 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: MajorDeltaCompactionOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.238s	user 0.147s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938769,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":655,"lbm_read_time_us":18414,"lbm_reads_lt_1ms":766,"lbm_write_time_us":38206,"lbm_writes_lt_1ms":743,"mutex_wait_us":273,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:15.256151 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8): 483 bytes on disk
I20260812 06:18:15.256820 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: UndoDeltaBlockGCOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.257864 29148 maintenance_manager.cc:419] P 9345a8c63a214c879aa91012bee90286: Scheduling FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8): perf score=18.063937
I20260812 06:18:15.283131 28965 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.030s	user 0.004s	sys 0.000s
I20260812 06:18:15.283872 28965 tablet_server.cc:179] TabletServer@127.28.73.65:0 shutting down...
I20260812 06:18:15.325789 29081 maintenance_manager.cc:643] P 9345a8c63a214c879aa91012bee90286: FlushDeltaMemStoresOp(764dde7b33cc437998d9f7db60b4e2d8) complete. Timing: real 0.068s	user 0.047s	sys 0.020s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26406,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:15.326558 28965 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:15.326998 28965 tablet_replica.cc:333] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286: stopping tablet replica
I20260812 06:18:15.327251 28965 raft_consensus.cc:2243] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.327518 28965 raft_consensus.cc:2272] T 764dde7b33cc437998d9f7db60b4e2d8 P 9345a8c63a214c879aa91012bee90286 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.343142 28965 tablet_server.cc:196] TabletServer@127.28.73.65:0 shutdown complete.
I20260812 06:18:15.348274 28965 master.cc:562] Master@127.28.73.126:46435 shutting down...
I20260812 06:18:15.352818 28965 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.353053 28965 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.353170 28965 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5073512762fd4fa78a841cf1f62cab68: stopping tablet replica
I20260812 06:18:15.366894 28965 master.cc:584] Master@127.28.73.126:46435 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5781 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:15.464507 28965 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.73.126:37883
I20260812 06:18:15.464941 28965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.467374 29190 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:18:15.467389 29188 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:18:15.467458 29187 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:18:15.467506 28965 server_base.cc:1061] running on GCE node
I20260812 06:18:15.467876 28965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.467921 28965 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:18:15.467936 28965 hybrid_clock.cc:648] HybridClock initialized: now 1786515495467937 us; error 0 us; skew 500 ppm
I20260812 06:18:15.468792 28965 webserver.cc:533] Webserver started at http://127.28.73.126:32831/ using document root <none> and password file <none>
I20260812 06:18:15.468981 28965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.469055 28965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.469157 28965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.469708 28965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/master-0-root/instance:
uuid: "3cf93fdd47ee4a16b6e1828c37008ad6"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-9zdj"
I20260812 06:18:15.471282 28965 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:15.472316 29195 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:18:15.472565 28965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:15.472659 28965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/master-0-root
uuid: "3cf93fdd47ee4a16b6e1828c37008ad6"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-9zdj"
I20260812 06:18:15.472766 28965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-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:18:15.490087 28965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.490574 28965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.495146 28965 rpc_server.cc:307] RPC server started. Bound to: 127.28.73.126:37883
I20260812 06:18:15.499130 29257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.73.126:37883 every 8 connection(s)
I20260812 06:18:15.506764 29258 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:18:15.508833 29258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6: Bootstrap starting.
I20260812 06:18:15.509668 29258 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.510823 29258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6: No bootstrap required, opened a new log
I20260812 06:18:15.511207 29258 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER }
I20260812 06:18:15.511368 29258 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.511405 29258 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3cf93fdd47ee4a16b6e1828c37008ad6, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.511523 29258 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [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: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER }
I20260812 06:18:15.511585 29258 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.511607 29258 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.511637 29258 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.512329 29258 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER }
I20260812 06:18:15.512450 29258 leader_election.cc:304] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [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: 3cf93fdd47ee4a16b6e1828c37008ad6; no voters: 
I20260812 06:18:15.512635 29258 leader_election.cc:290] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.512836 29262 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.513047 29262 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 1 LEADER]: Becoming Leader. State: Replica: 3cf93fdd47ee4a16b6e1828c37008ad6, State: Running, Role: LEADER
I20260812 06:18:15.513172 29258 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:15.513216 29262 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [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: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER }
I20260812 06:18:15.513715 29264 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3cf93fdd47ee4a16b6e1828c37008ad6. Latest consensus state: current_term: 1 leader_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER } }
I20260812 06:18:15.513810 29264 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.513693 29263 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf93fdd47ee4a16b6e1828c37008ad6" member_type: VOTER } }
I20260812 06:18:15.513867 29263 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.514101 29267 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:15.515026 29267 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:15.515336 28965 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:15.517257 29267 catalog_manager.cc:1383] Generated new cluster ID: 8f8995003649485eae65b7379fb63bbb
I20260812 06:18:15.517323 29267 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:15.523790 29267 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:15.524482 29267 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:15.530925 29267 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6: Generated new TSK 0
I20260812 06:18:15.531167 29267 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:15.548100 28965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.550505 29281 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:18:15.550624 29284 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:18:15.550649 29282 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:18:15.551126 28965 server_base.cc:1061] running on GCE node
I20260812 06:18:15.551357 28965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.551407 28965 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:18:15.551433 28965 hybrid_clock.cc:648] HybridClock initialized: now 1786515495551434 us; error 0 us; skew 500 ppm
I20260812 06:18:15.552346 28965 webserver.cc:533] Webserver started at http://127.28.73.65:38425/ using document root <none> and password file <none>
I20260812 06:18:15.552493 28965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.552541 28965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.552596 28965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.553026 28965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/instance:
uuid: "dbdbf306375343cdb17c5c83193b8528"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-9zdj"
I20260812 06:18:15.554669 28965 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:15.555572 29289 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:18:15.555810 28965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:15.555876 28965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root
uuid: "dbdbf306375343cdb17c5c83193b8528"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-9zdj"
I20260812 06:18:15.555987 28965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-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:18:15.568048 28965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.568540 28965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.568894 28965 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:15.569450 28965 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:15.569520 28965 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.569583 28965 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:15.569692 28965 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.574757 28965 rpc_server.cc:307] RPC server started. Bound to: 127.28.73.65:33621
I20260812 06:18:15.575568 29368 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.73.65:33621 every 8 connection(s)
I20260812 06:18:15.585399 29369 heartbeater.cc:344] Connected to a master server at 127.28.73.126:37883
I20260812 06:18:15.585608 29369 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:15.585951 29369 heartbeater.cc:507] Master 127.28.73.126:37883 requested a full tablet report, sending...
I20260812 06:18:15.586706 29216 ts_manager.cc:194] Registered new tserver with Master: dbdbf306375343cdb17c5c83193b8528 (127.28.73.65:33621)
I20260812 06:18:15.586905 28965 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011197765s
I20260812 06:18:15.587764 29216 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47136
I20260812 06:18:15.595121 29216 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47138:
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:18:15.604843 29323 tablet_service.cc:1511] Processing CreateTablet for tablet de76d095bb944246bf2884bc05972e06 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b5db1876fe5542cd9946ac68515668e4]), partition=
I20260812 06:18:15.605194 29323 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet de76d095bb944246bf2884bc05972e06. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:15.607826 29381 tablet_bootstrap.cc:492] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Bootstrap starting.
I20260812 06:18:15.608724 29381 tablet_bootstrap.cc:654] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.610054 29381 tablet_bootstrap.cc:492] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: No bootstrap required, opened a new log
I20260812 06:18:15.610155 29381 ts_tablet_manager.cc:1403] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:15.610620 29381 raft_consensus.cc:359] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbdbf306375343cdb17c5c83193b8528" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 33621 } }
I20260812 06:18:15.610713 29381 raft_consensus.cc:385] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.610737 29381 raft_consensus.cc:740] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dbdbf306375343cdb17c5c83193b8528, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.610837 29381 consensus_queue.cc:260] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [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: "dbdbf306375343cdb17c5c83193b8528" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 33621 } }
I20260812 06:18:15.610896 29381 raft_consensus.cc:399] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.610918 29381 raft_consensus.cc:493] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.610952 29381 raft_consensus.cc:3060] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.611675 29381 raft_consensus.cc:515] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbdbf306375343cdb17c5c83193b8528" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 33621 } }
I20260812 06:18:15.611799 29381 leader_election.cc:304] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [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: dbdbf306375343cdb17c5c83193b8528; no voters: 
I20260812 06:18:15.611976 29381 leader_election.cc:290] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.612257 29381 ts_tablet_manager.cc:1434] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:15.612254 29384 raft_consensus.cc:2804] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.612444 29369 heartbeater.cc:499] Master 127.28.73.126:37883 was elected leader, sending a full tablet report...
I20260812 06:18:15.612488 29384 raft_consensus.cc:697] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 1 LEADER]: Becoming Leader. State: Replica: dbdbf306375343cdb17c5c83193b8528, State: Running, Role: LEADER
I20260812 06:18:15.612653 29384 consensus_queue.cc:237] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [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: "dbdbf306375343cdb17c5c83193b8528" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 33621 } }
I20260812 06:18:15.614485 29215 catalog_manager.cc:5719] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 reported cstate change: term changed from 0 to 1, leader changed from <none> to dbdbf306375343cdb17c5c83193b8528 (127.28.73.65). New cstate: current_term: 1 leader_uuid: "dbdbf306375343cdb17c5c83193b8528" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbdbf306375343cdb17c5c83193b8528" member_type: VOTER last_known_addr { host: "127.28.73.65" port: 33621 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:15.679276 28965 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.014s	sys 0.009s
I20260812 06:18:15.826076 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushMRSOp(de76d095bb944246bf2884bc05972e06): perf score=19.054940
I20260812 06:18:16.002326 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushMRSOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.176s	user 0.118s	sys 0.049s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1028,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42925,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:16.003095 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 20743880 bytes of WAL
I20260812 06:18:16.003368 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 2 log segments from log reader
I20260812 06:18:16.003441 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000001 (ops 1-6)
I20260812 06:18:16.003487 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000002 (ops 7-11)
I20260812 06:18:16.010193 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:16.010699 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06): 16411392 bytes on disk
I20260812 06:18:16.011204 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.011663 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:16.029345 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.018s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.029870 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:16.193186 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.163s	user 0.116s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":674,"lbm_read_time_us":12351,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28298,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":349,"threads_started":5,"update_count":2000}
I20260812 06:18:16.193879 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=11.118625
I20260812 06:18:16.253835 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.060s	user 0.020s	sys 0.037s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20870,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:16.254551 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=3.181125
I20260812 06:18:16.269891 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4676998,"delete_count":0,"lbm_write_time_us":6044,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:18:16.270504 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=1.196750
I20260812 06:18:16.280117 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":3421,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:16.280616 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:16.481263 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.200s	user 0.150s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774788,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":737,"lbm_read_time_us":15033,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31833,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:18:16.481834 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:16.547017 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.065s	user 0.027s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20540,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.547608 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:16.559047 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.559648 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:16.762637 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.203s	user 0.124s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":478,"lbm_read_time_us":13764,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33146,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:18:16.763423 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:16.848801 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.085s	user 0.014s	sys 0.043s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":45551,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.849582 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:16.869549 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.870364 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:17.068787 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.198s	user 0.109s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1359,"lbm_read_time_us":14159,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28887,"lbm_writes_lt_1ms":543,"mutex_wait_us":391,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2500}
I20260812 06:18:17.069496 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:17.125017 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.055s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20851,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.125710 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:17.139660 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.140370 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:17.333045 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.193s	user 0.110s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1243,"lbm_read_time_us":10517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31231,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:17.333801 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:17.389294 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.055s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23388,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.389961 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:17.402249 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.402781 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushMRSOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:17.436643 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushMRSOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1574,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2081,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:17.437430 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 112239264 bytes of WAL
I20260812 06:18:17.437767 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 11 log segments from log reader
I20260812 06:18:17.437855 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000003 (ops 12-16)
I20260812 06:18:17.437915 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000004 (ops 17-21)
I20260812 06:18:17.437968 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000005 (ops 22-26)
I20260812 06:18:17.438011 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000006 (ops 27-31)
I20260812 06:18:17.438053 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000007 (ops 32-36)
I20260812 06:18:17.438095 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000008 (ops 37-41)
I20260812 06:18:17.438134 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000009 (ops 42-46)
I20260812 06:18:17.438175 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000010 (ops 47-51)
I20260812 06:18:17.438215 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000011 (ops 52-56)
I20260812 06:18:17.438256 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000012 (ops 57-60)
I20260812 06:18:17.438295 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000013 (ops 61-65)
I20260812 06:18:17.466130 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:17.472335 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06): 462 bytes on disk
I20260812 06:18:17.472926 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.473554 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:17.499944 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.026s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.500494 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 12017983 bytes of WAL
I20260812 06:18:17.500844 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 1 log segments from log reader
I20260812 06:18:17.500897 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000014 (ops 66-70)
I20260812 06:18:17.503660 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:17.504145 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:17.517834 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.013s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.518362 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:17.782722 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.264s	user 0.156s	sys 0.107s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":836,"lbm_read_time_us":17736,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44200,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:18:17.783453 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=18.063937
I20260812 06:18:17.855471 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.072s	user 0.039s	sys 0.028s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":31312,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.856122 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:17.869849 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.870404 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:18.107251 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.237s	user 0.170s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1025,"lbm_read_time_us":17349,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39649,"lbm_writes_lt_1ms":643,"mutex_wait_us":325,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:18:18.108055 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:18.157140 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21716,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.157737 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:18.183712 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.026s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.184247 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:18.196991 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4923,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.197739 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:18.433180 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.235s	user 0.162s	sys 0.073s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1135,"lbm_read_time_us":14418,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39836,"lbm_writes_lt_1ms":643,"mutex_wait_us":401,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3000}
I20260812 06:18:18.433881 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:18.487537 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23872,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.488245 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:18.513511 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.514194 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:18.526710 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4818,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.527338 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:18.763619 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.236s	user 0.124s	sys 0.091s 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":819,"lbm_read_time_us":16691,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39766,"lbm_writes_lt_1ms":643,"mutex_wait_us":79,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35840,"update_count":3000}
I20260812 06:18:18.764381 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=18.063937
I20260812 06:18:18.837572 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.073s	user 0.041s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31953,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:18.838260 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:18.850473 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.850961 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:19.066162 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.215s	user 0.130s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":18585,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36209,"lbm_writes_lt_1ms":643,"mutex_wait_us":470,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:19.066859 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:19.113947 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.047s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20990,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.114509 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:19.136044 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.021s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.136678 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushMRSOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:19.182505 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushMRSOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.046s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1610,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1848,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:19.183456 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06): 493 bytes on disk
I20260812 06:18:19.183975 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.184661 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=3.181125
I20260812 06:18:19.197919 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4767,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:19.198521 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 121006384 bytes of WAL
I20260812 06:18:19.198833 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 12 log segments from log reader
I20260812 06:18:19.198897 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000015 (ops 71-75)
I20260812 06:18:19.198941 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000016 (ops 76-80)
I20260812 06:18:19.198964 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000017 (ops 81-85)
I20260812 06:18:19.198997 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000018 (ops 86-90)
I20260812 06:18:19.199019 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000019 (ops 91-94)
I20260812 06:18:19.199061 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000020 (ops 95-99)
I20260812 06:18:19.199096 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000021 (ops 100-104)
I20260812 06:18:19.199119 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000022 (ops 105-109)
I20260812 06:18:19.199148 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000023 (ops 110-114)
I20260812 06:18:19.199172 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000024 (ops 115-119)
I20260812 06:18:19.199214 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000025 (ops 120-124)
I20260812 06:18:19.199250 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000026 (ops 125-129)
I20260812 06:18:19.228662 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.030s	user 0.001s	sys 0.026s Metrics: {}
I20260812 06:18:19.229164 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:19.253263 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.024s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.253875 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 12018006 bytes of WAL
I20260812 06:18:19.254144 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 1 log segments from log reader
I20260812 06:18:19.254215 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000027 (ops 130-134)
I20260812 06:18:19.256883 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:19.257357 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:19.270648 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.271364 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:19.492727 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.221s	user 0.181s	sys 0.039s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":206,"lbm_read_time_us":17463,"lbm_reads_lt_1ms":875,"lbm_write_time_us":46462,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":104,"threads_started":1,"update_count":4000}
I20260812 06:18:19.493430 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=18.063937
I20260812 06:18:19.559700 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.066s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30143,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.560415 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:19.591034 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.030s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.591750 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:19.802884 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.211s	user 0.127s	sys 0.083s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":17177,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34406,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:18:19.803570 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=14.095187
I20260812 06:18:19.873654 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.070s	user 0.029s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24598,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.875147 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=3.181125
I20260812 06:18:19.889814 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":4944,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:18:19.890349 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:19.902040 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.011s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":4528,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:19.902591 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:20.139644 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.237s	user 0.155s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877217,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":276,"lbm_read_time_us":17135,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36337,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":3000}
I20260812 06:18:20.141048 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=18.063937
I20260812 06:18:20.215672 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.074s	user 0.048s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29836,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.216246 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:20.228008 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.229079 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:20.442714 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.213s	user 0.138s	sys 0.067s 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":858,"lbm_read_time_us":15273,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35286,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":107008,"update_count":3000}
I20260812 06:18:20.443627 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=16.079562
I20260812 06:18:20.487777 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.044s	user 0.022s	sys 0.020s Metrics: {"bytes_written":17886768,"delete_count":0,"lbm_write_time_us":20340,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2180}
I20260812 06:18:20.488529 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=1.196750
I20260812 06:18:20.510573 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.022s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":4469,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:18:20.511132 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:20.523138 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.523676 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:20.730904 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.207s	user 0.124s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877181,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":171,"lbm_read_time_us":15158,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34887,"lbm_writes_lt_1ms":643,"mutex_wait_us":61,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:20.731980 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=16.079562
I20260812 06:18:20.793808 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.062s	user 0.053s	sys 0.008s Metrics: {"bytes_written":17804729,"delete_count":0,"lbm_write_time_us":27879,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:18:20.794425 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=1.196750
I20260812 06:18:20.811580 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.017s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":3610,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:20.812114 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:20.823184 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.823745 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushMRSOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:20.862061 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushMRSOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.038s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1621,"drs_written":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2603,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:20.862787 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling LogGCOp(de76d095bb944246bf2884bc05972e06): free 125616932 bytes of WAL
I20260812 06:18:20.863046 29295 log_reader.cc:385] T de76d095bb944246bf2884bc05972e06: removed 13 log segments from log reader
I20260812 06:18:20.863108 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000028 (ops 135-139)
I20260812 06:18:20.863164 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000029 (ops 140-144)
I20260812 06:18:20.863222 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000030 (ops 145-148)
I20260812 06:18:20.863265 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000031 (ops 149-153)
I20260812 06:18:20.863328 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000032 (ops 154-158)
I20260812 06:18:20.863368 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000033 (ops 159-162)
I20260812 06:18:20.863404 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000034 (ops 163-167)
I20260812 06:18:20.863441 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000035 (ops 168-172)
I20260812 06:18:20.863477 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000036 (ops 173-176)
I20260812 06:18:20.863513 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000037 (ops 177-181)
I20260812 06:18:20.863550 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000038 (ops 182-186)
I20260812 06:18:20.863587 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000039 (ops 187-191)
I20260812 06:18:20.863623 29295 log.cc:1079] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: Deleting log segment in path: /tmp/dist-test-taskON4x_I/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489672495-28965-0/minicluster-data/ts-0-root/wals/de76d095bb944246bf2884bc05972e06/wal-000000040 (ops 192-196)
I20260812 06:18:20.894753 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: LogGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.032s	user 0.004s	sys 0.027s Metrics: {}
I20260812 06:18:20.895220 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06): 492 bytes on disk
I20260812 06:18:20.895705 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: UndoDeltaBlockGCOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.896277 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:20.920953 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.025s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.921540 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06): perf score=2.188937
I20260812 06:18:20.937839 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: FlushDeltaMemStoresOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.938500 29370 maintenance_manager.cc:419] P dbdbf306375343cdb17c5c83193b8528: Scheduling MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06): perf score=1.000000
I20260812 06:18:20.987320 28965 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.308s	user 1.909s	sys 0.188s
I20260812 06:18:21.096524 28965 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.109s	user 0.002s	sys 0.000s
I20260812 06:18:21.097240 28965 tablet_server.cc:179] TabletServer@127.28.73.65:0 shutting down...
I20260812 06:18:21.181149 29295 maintenance_manager.cc:643] P dbdbf306375343cdb17c5c83193b8528: MajorDeltaCompactionOp(de76d095bb944246bf2884bc05972e06) complete. Timing: real 0.242s	user 0.170s	sys 0.072s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082254,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":532,"lbm_read_time_us":21163,"lbm_reads_lt_1ms":871,"lbm_write_time_us":44051,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":84,"threads_started":1,"update_count":4000}
I20260812 06:18:21.182132 28965 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:21.182646 28965 tablet_replica.cc:333] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528: stopping tablet replica
I20260812 06:18:21.182857 28965 raft_consensus.cc:2243] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.183054 28965 raft_consensus.cc:2272] T de76d095bb944246bf2884bc05972e06 P dbdbf306375343cdb17c5c83193b8528 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.188890 28965 tablet_server.cc:196] TabletServer@127.28.73.65:0 shutdown complete.
I20260812 06:18:21.254215 28965 master.cc:562] Master@127.28.73.126:37883 shutting down...
I20260812 06:18:21.257691 28965 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.257939 28965 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.258026 28965 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3cf93fdd47ee4a16b6e1828c37008ad6: stopping tablet replica
I20260812 06:18:21.270877 28965 master.cc:584] Master@127.28.73.126:37883 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5898 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11680 ms total)

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