[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:38.406275 14217 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.226.126:35997
I20260812 06:19:38.407240 14217 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:38.407850 14217 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:38.413985 14217 server_base.cc:1061] running on GCE node
W20260812 06:19:38.414080 14228 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.414237 14236 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.414325 14231 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:19:38.414819 14217 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.414917 14217 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.414961 14217 hybrid_clock.cc:648] HybridClock initialized: now 1786515578414959 us; error 0 us; skew 500 ppm
I20260812 06:19:38.416615 14217 webserver.cc:533] Webserver started at http://127.13.226.126:33517/ using document root <none> and password file <none>
I20260812 06:19:38.417104 14217 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.417162 14217 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.417374 14217 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.418918 14217 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/master-0-root/instance:
uuid: "3d56169448354657a10f0ca1b5dff656"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-21b9"
I20260812 06:19:38.422154 14217 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.001s
I20260812 06:19:38.424155 14249 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.425063 14217 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:38.425163 14217 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/master-0-root
uuid: "3d56169448354657a10f0ca1b5dff656"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-21b9"
I20260812 06:19:38.425253 14217 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.441839 14217 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.442442 14217 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:38.442596 14217 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.449821 14217 rpc_server.cc:307] RPC server started. Bound to: 127.13.226.126:35997
I20260812 06:19:38.449867 14330 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.226.126:35997 every 8 connection(s)
I20260812 06:19:38.452052 14331 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.457265 14331 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: Bootstrap starting.
I20260812 06:19:38.459532 14331 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.460410 14331 log.cc:826] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:38.461941 14331 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: No bootstrap required, opened a new log
I20260812 06:19:38.464607 14331 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER }
I20260812 06:19:38.464766 14331 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.464833 14331 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3d56169448354657a10f0ca1b5dff656, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.465400 14331 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [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: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER }
I20260812 06:19:38.465541 14331 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.465606 14331 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.465723 14331 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.466445 14331 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER }
I20260812 06:19:38.466846 14331 leader_election.cc:304] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [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: 3d56169448354657a10f0ca1b5dff656; no voters: 
I20260812 06:19:38.467133 14331 leader_election.cc:290] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.467232 14336 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.467471 14336 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 1 LEADER]: Becoming Leader. State: Replica: 3d56169448354657a10f0ca1b5dff656, State: Running, Role: LEADER
I20260812 06:19:38.467901 14336 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [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: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER }
I20260812 06:19:38.468206 14331 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:38.469733 14338 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3d56169448354657a10f0ca1b5dff656" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER } }
I20260812 06:19:38.469763 14339 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3d56169448354657a10f0ca1b5dff656. Latest consensus state: current_term: 1 leader_uuid: "3d56169448354657a10f0ca1b5dff656" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d56169448354657a10f0ca1b5dff656" member_type: VOTER } }
I20260812 06:19:38.469853 14339 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.469852 14338 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.470458 14217 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:38.472270 14360 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:38.472334 14360 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:38.472429 14352 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:38.473119 14352 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:38.477427 14352 catalog_manager.cc:1383] Generated new cluster ID: 94d6fbba6e9042b8a0f3209fa05f6903
I20260812 06:19:38.477486 14352 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:38.484870 14352 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:38.485986 14352 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:38.494016 14352 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: Generated new TSK 0
I20260812 06:19:38.494683 14352 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:38.503234 14217 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.505776 14371 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.505805 14365 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.506026 14217 server_base.cc:1061] running on GCE node
W20260812 06:19:38.506108 14367 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:19:38.506317 14217 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.506362 14217 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.506376 14217 hybrid_clock.cc:648] HybridClock initialized: now 1786515578506376 us; error 0 us; skew 500 ppm
I20260812 06:19:38.507223 14217 webserver.cc:533] Webserver started at http://127.13.226.65:36641/ using document root <none> and password file <none>
I20260812 06:19:38.507406 14217 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.507457 14217 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.507531 14217 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.507897 14217 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/instance:
uuid: "93357ec5d76046bc9174033c0eccdbdf"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-21b9"
I20260812 06:19:38.509341 14217 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:38.510249 14385 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.510504 14217 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:38.510578 14217 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root
uuid: "93357ec5d76046bc9174033c0eccdbdf"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-21b9"
I20260812 06:19:38.510648 14217 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.529155 14217 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.529637 14217 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.530107 14217 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:38.530933 14217 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:38.530995 14217 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.531044 14217 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:38.531095 14217 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.537163 14217 rpc_server.cc:307] RPC server started. Bound to: 127.13.226.65:34547
I20260812 06:19:38.537207 14493 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.226.65:34547 every 8 connection(s)
I20260812 06:19:38.550603 14494 heartbeater.cc:344] Connected to a master server at 127.13.226.126:35997
I20260812 06:19:38.550853 14494 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:38.551433 14494 heartbeater.cc:507] Master 127.13.226.126:35997 requested a full tablet report, sending...
I20260812 06:19:38.552956 14280 ts_manager.cc:194] Registered new tserver with Master: 93357ec5d76046bc9174033c0eccdbdf (127.13.226.65:34547)
I20260812 06:19:38.553283 14217 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015516276s
I20260812 06:19:38.554522 14280 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48774
I20260812 06:19:38.562865 14280 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48784:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:38.577445 14436 tablet_service.cc:1511] Processing CreateTablet for tablet 41e4f0b4e683418ab1136e787643cec1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=519c5b480cd041f6aa8efb9ffcf12e4a]), partition=
I20260812 06:19:38.577978 14436 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 41e4f0b4e683418ab1136e787643cec1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.580431 14514 tablet_bootstrap.cc:492] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Bootstrap starting.
I20260812 06:19:38.581501 14514 tablet_bootstrap.cc:654] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.582713 14514 tablet_bootstrap.cc:492] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: No bootstrap required, opened a new log
I20260812 06:19:38.582811 14514 ts_tablet_manager.cc:1403] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:38.583317 14514 raft_consensus.cc:359] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93357ec5d76046bc9174033c0eccdbdf" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 34547 } }
I20260812 06:19:38.583441 14514 raft_consensus.cc:385] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.583468 14514 raft_consensus.cc:740] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 93357ec5d76046bc9174033c0eccdbdf, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.583617 14514 consensus_queue.cc:260] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [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: "93357ec5d76046bc9174033c0eccdbdf" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 34547 } }
I20260812 06:19:38.583694 14514 raft_consensus.cc:399] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.583732 14514 raft_consensus.cc:493] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.583789 14514 raft_consensus.cc:3060] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.584477 14514 raft_consensus.cc:515] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93357ec5d76046bc9174033c0eccdbdf" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 34547 } }
I20260812 06:19:38.584607 14514 leader_election.cc:304] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [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: 93357ec5d76046bc9174033c0eccdbdf; no voters: 
I20260812 06:19:38.584810 14514 leader_election.cc:290] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.584928 14516 raft_consensus.cc:2804] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.585191 14514 ts_tablet_manager.cc:1434] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:38.585278 14516 raft_consensus.cc:697] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 1 LEADER]: Becoming Leader. State: Replica: 93357ec5d76046bc9174033c0eccdbdf, State: Running, Role: LEADER
I20260812 06:19:38.585492 14516 consensus_queue.cc:237] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [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: "93357ec5d76046bc9174033c0eccdbdf" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 34547 } }
I20260812 06:19:38.585640 14494 heartbeater.cc:499] Master 127.13.226.126:35997 was elected leader, sending a full tablet report...
I20260812 06:19:38.588047 14280 catalog_manager.cc:5719] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf reported cstate change: term changed from 0 to 1, leader changed from <none> to 93357ec5d76046bc9174033c0eccdbdf (127.13.226.65). New cstate: current_term: 1 leader_uuid: "93357ec5d76046bc9174033c0eccdbdf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93357ec5d76046bc9174033c0eccdbdf" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 34547 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:38.649248 14217 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.012s
I20260812 06:19:38.788218 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushMRSOp(41e4f0b4e683418ab1136e787643cec1): perf score=19.054940
I20260812 06:19:38.980691 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushMRSOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.192s	user 0.155s	sys 0.036s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":492,"delete_count":0,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":759,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48533,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":129,"threads_started":1,"update_count":2000}
I20260812 06:19:38.982932 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling LogGCOp(41e4f0b4e683418ab1136e787643cec1): free 20743880 bytes of WAL
I20260812 06:19:38.983362 14397 log_reader.cc:385] T 41e4f0b4e683418ab1136e787643cec1: removed 2 log segments from log reader
I20260812 06:19:38.983453 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000001 (ops 1-6)
I20260812 06:19:38.983569 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000002 (ops 7-11)
I20260812 06:19:38.988906 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: LogGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:38.989336 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1): 16411393 bytes on disk
I20260812 06:19:38.989993 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.990449 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=3.181125
I20260812 06:19:39.005775 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5985,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.006280 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:39.018636 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4765,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.019079 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:39.203679 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.184s	user 0.121s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":435,"lbm_read_time_us":11394,"lbm_reads_lt_1ms":669,"lbm_write_time_us":32297,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":221,"threads_started":5,"update_count":3000}
I20260812 06:19:39.204201 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:39.260862 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.056s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19310,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.261461 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:39.272050 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.272459 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:39.441299 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.169s	user 0.126s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":876,"lbm_read_time_us":10627,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29508,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:39.441754 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:39.498270 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.056s	user 0.032s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23423,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.498899 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:39.509703 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.510356 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:39.691525 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.181s	user 0.124s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":112,"lbm_read_time_us":13590,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29230,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:39.691978 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:39.747249 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.055s	user 0.012s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.747900 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:39.763191 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.763782 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:39.925453 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.161s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":760,"lbm_read_time_us":11980,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27563,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:19:39.926009 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=11.118625
I20260812 06:19:39.960199 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.034s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14255,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.960709 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:39.986505 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.026s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4955,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.986997 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.003850 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.017s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.004454 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:40.176908 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.172s	user 0.096s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":103,"lbm_read_time_us":13768,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27467,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:19:40.177582 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:40.205281 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.027s	user 0.025s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.205744 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.219063 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.219795 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushMRSOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:40.246968 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushMRSOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1273,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1614,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:40.247823 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling LogGCOp(41e4f0b4e683418ab1136e787643cec1): free 124710236 bytes of WAL
I20260812 06:19:40.248059 14397 log_reader.cc:385] T 41e4f0b4e683418ab1136e787643cec1: removed 12 log segments from log reader
I20260812 06:19:40.248131 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000003 (ops 12-16)
I20260812 06:19:40.248176 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000004 (ops 17-21)
I20260812 06:19:40.248211 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000005 (ops 22-26)
I20260812 06:19:40.248234 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000006 (ops 27-31)
I20260812 06:19:40.248263 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000007 (ops 32-36)
I20260812 06:19:40.248291 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000008 (ops 37-41)
I20260812 06:19:40.248322 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000009 (ops 42-46)
I20260812 06:19:40.248354 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000010 (ops 47-51)
I20260812 06:19:40.248383 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000011 (ops 52-56)
I20260812 06:19:40.248410 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000012 (ops 57-61)
I20260812 06:19:40.248437 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000013 (ops 62-66)
I20260812 06:19:40.248468 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000014 (ops 67-71)
I20260812 06:19:40.275200 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: LogGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:40.275689 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1): 472 bytes on disk
I20260812 06:19:40.276183 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.276695 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=3.181125
I20260812 06:19:40.296558 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.020s	user 0.005s	sys 0.013s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.297008 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.310815 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5175,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.311303 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:40.507519 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.196s	user 0.116s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":451,"lbm_read_time_us":14185,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31442,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:40.508023 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:40.563091 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.055s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19666,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.563673 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.574417 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.574844 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:40.739558 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.165s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":11376,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26982,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:19:40.740056 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=11.118625
I20260812 06:19:40.774544 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.034s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14753,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.774983 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.786815 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.787334 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:40.925237 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.138s	user 0.096s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":8007,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23389,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:40.925917 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:40.962407 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.036s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15481,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.962854 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:40.974128 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.974716 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.099056 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.124s	user 0.112s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":9524,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22005,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:41.099627 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:41.133131 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.033s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14115,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.133677 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:41.147495 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.147993 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.267664 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.119s	user 0.086s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":8161,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23018,"lbm_writes_lt_1ms":443,"mutex_wait_us":214,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:19:41.268149 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:41.321229 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.053s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13433,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.321748 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:41.337208 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.337747 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.477634 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.140s	user 0.099s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":11333,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20524,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.478145 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:41.518551 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.040s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15105,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.519043 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:41.529037 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.529620 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.646467 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.117s	user 0.092s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":8741,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20517,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.646961 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=10.126437
I20260812 06:19:41.681017 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.034s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.681557 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushMRSOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.734817 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushMRSOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.053s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1171,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1389,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:41.735569 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling LogGCOp(41e4f0b4e683418ab1136e787643cec1): free 124710309 bytes of WAL
I20260812 06:19:41.735803 14397 log_reader.cc:385] T 41e4f0b4e683418ab1136e787643cec1: removed 12 log segments from log reader
I20260812 06:19:41.735852 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000015 (ops 72-76)
I20260812 06:19:41.735883 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000016 (ops 77-81)
I20260812 06:19:41.735916 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000017 (ops 82-86)
I20260812 06:19:41.735963 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000018 (ops 87-91)
I20260812 06:19:41.735997 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000019 (ops 92-96)
I20260812 06:19:41.736029 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000020 (ops 97-101)
I20260812 06:19:41.736061 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000021 (ops 102-106)
I20260812 06:19:41.736092 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000022 (ops 107-111)
I20260812 06:19:41.736124 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000023 (ops 112-116)
I20260812 06:19:41.736155 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000024 (ops 117-121)
I20260812 06:19:41.736186 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000025 (ops 122-126)
I20260812 06:19:41.736217 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000026 (ops 127-131)
I20260812 06:19:41.756759 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: LogGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:41.757135 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1): 482 bytes on disk
I20260812 06:19:41.757529 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.758013 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=7.149875
I20260812 06:19:41.786971 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.029s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12336,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:41.787482 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:41.797708 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3376,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.798151 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:41.953842 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.156s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":587,"lbm_read_time_us":12899,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29474,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":28288,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:19:41.954427 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:42.001147 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.047s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20431,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:42.001565 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:42.014611 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.015141 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:42.174880 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.160s	user 0.107s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":9151,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29976,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:42.175463 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:42.225422 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.050s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21079,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.225931 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:42.379374 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.153s	user 0.101s	sys 0.046s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":612,"lbm_read_time_us":10568,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23103,"lbm_writes_lt_1ms":443,"mutex_wait_us":258,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:19:42.379877 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:42.426633 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.047s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.427183 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:42.437666 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.438256 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:42.622586 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.183s	user 0.088s	sys 0.084s 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":523,"lbm_read_time_us":10532,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30266,"lbm_writes_lt_1ms":543,"mutex_wait_us":223,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:42.623104 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=14.095187
I20260812 06:19:42.665576 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.042s	user 0.016s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16366,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.666155 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:42.678108 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.678647 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:42.826102 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.147s	user 0.109s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1022,"lbm_read_time_us":9847,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26148,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:42.826632 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=11.118625
I20260812 06:19:42.867218 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17500,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:42.867915 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:42.891127 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5351,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:42.891600 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:42.900717 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3302,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:42.901278 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:43.045261 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.144s	user 0.101s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":621,"lbm_read_time_us":9974,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26077,"lbm_writes_lt_1ms":543,"mutex_wait_us":240,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:43.045806 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=11.118625
I20260812 06:19:43.082576 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15928,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.083174 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:43.104511 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.021s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.105096 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:43.114995 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.115625 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushMRSOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:43.144752 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushMRSOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.029s	user 0.019s	sys 0.009s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1208,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1550,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:43.145437 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling LogGCOp(41e4f0b4e683418ab1136e787643cec1): free 132571650 bytes of WAL
I20260812 06:19:43.145679 14397 log_reader.cc:385] T 41e4f0b4e683418ab1136e787643cec1: removed 13 log segments from log reader
I20260812 06:19:43.145741 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000027 (ops 132-136)
I20260812 06:19:43.145782 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000028 (ops 137-141)
I20260812 06:19:43.145817 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000029 (ops 142-146)
I20260812 06:19:43.145848 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000030 (ops 147-151)
I20260812 06:19:43.145876 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000031 (ops 152-156)
I20260812 06:19:43.145901 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000032 (ops 157-160)
I20260812 06:19:43.145926 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000033 (ops 161-165)
I20260812 06:19:43.145957 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000034 (ops 166-170)
I20260812 06:19:43.145989 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000035 (ops 171-175)
I20260812 06:19:43.146018 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000036 (ops 176-180)
I20260812 06:19:43.146044 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000037 (ops 181-185)
I20260812 06:19:43.146067 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000038 (ops 186-190)
I20260812 06:19:43.146092 14397 log.cc:1079] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/41e4f0b4e683418ab1136e787643cec1/wal-000000039 (ops 191-194)
I20260812 06:19:43.170552 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: LogGCOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:43.171000 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1): 482 bytes on disk
I20260812 06:19:43.171478 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: UndoDeltaBlockGCOp(41e4f0b4e683418ab1136e787643cec1) 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:19:43.172216 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=3.181125
I20260812 06:19:43.184496 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:43.184959 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=2.188937
I20260812 06:19:43.201542 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3295,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.202055 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1): perf score=1.000000
I20260812 06:19:43.302778 14217 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.653s	user 1.648s	sys 0.163s
I20260812 06:19:43.398488 14217 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.095s	user 0.001s	sys 0.000s
I20260812 06:19:43.399080 14217 tablet_server.cc:179] TabletServer@127.13.226.65:0 shutting down...
I20260812 06:19:43.403964 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: MajorDeltaCompactionOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.202s	user 0.125s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":541,"lbm_read_time_us":14097,"lbm_reads_lt_1ms":771,"lbm_write_time_us":32016,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18176,"thread_start_us":675,"threads_started":1,"update_count":3500}
I20260812 06:19:43.404490 14497 maintenance_manager.cc:419] P 93357ec5d76046bc9174033c0eccdbdf: Scheduling FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1): perf score=6.157687
I20260812 06:19:43.423233 14397 maintenance_manager.cc:643] P 93357ec5d76046bc9174033c0eccdbdf: FlushDeltaMemStoresOp(41e4f0b4e683418ab1136e787643cec1) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":7967,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:43.423884 14217 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:43.424314 14217 tablet_replica.cc:333] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf: stopping tablet replica
I20260812 06:19:43.424523 14217 raft_consensus.cc:2243] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.424710 14217 raft_consensus.cc:2272] T 41e4f0b4e683418ab1136e787643cec1 P 93357ec5d76046bc9174033c0eccdbdf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.439095 14217 tablet_server.cc:196] TabletServer@127.13.226.65:0 shutdown complete.
I20260812 06:19:43.460747 14217 master.cc:562] Master@127.13.226.126:35997 shutting down...
I20260812 06:19:43.463965 14217 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.464143 14217 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.464212 14217 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3d56169448354657a10f0ca1b5dff656: stopping tablet replica
I20260812 06:19:43.476473 14217 master.cc:584] Master@127.13.226.126:35997 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5140 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:43.557672 14217 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.226.126:43757
I20260812 06:19:43.558089 14217 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.560309 14546 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.560324 14547 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.560472 14550 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.560385 14217 server_base.cc:1061] running on GCE node
I20260812 06:19:43.560729 14217 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.560770 14217 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.560783 14217 hybrid_clock.cc:648] HybridClock initialized: now 1786515583560783 us; error 0 us; skew 500 ppm
I20260812 06:19:43.561537 14217 webserver.cc:533] Webserver started at http://127.13.226.126:33685/ using document root <none> and password file <none>
I20260812 06:19:43.561671 14217 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.561712 14217 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.561767 14217 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.562095 14217 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/master-0-root/instance:
uuid: "3c5dc9a4a9af47c29efa291ab678e470"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-21b9"
I20260812 06:19:43.564209 14217 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:43.565099 14558 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.565325 14217 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:43.565389 14217 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/master-0-root
uuid: "3c5dc9a4a9af47c29efa291ab678e470"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-21b9"
I20260812 06:19:43.565461 14217 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.573175 14217 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.573473 14217 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.577507 14217 rpc_server.cc:307] RPC server started. Bound to: 127.13.226.126:43757
I20260812 06:19:43.582350 14646 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.226.126:43757 every 8 connection(s)
I20260812 06:19:43.582757 14647 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.584578 14647 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470: Bootstrap starting.
I20260812 06:19:43.585302 14647 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.586290 14647 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470: No bootstrap required, opened a new log
I20260812 06:19:43.586654 14647 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER }
I20260812 06:19:43.586740 14647 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.586771 14647 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c5dc9a4a9af47c29efa291ab678e470, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.586903 14647 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [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: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER }
I20260812 06:19:43.586973 14647 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.587010 14647 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.587057 14647 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.587738 14647 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER }
I20260812 06:19:43.587863 14647 leader_election.cc:304] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [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: 3c5dc9a4a9af47c29efa291ab678e470; no voters: 
I20260812 06:19:43.588032 14647 leader_election.cc:290] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.588137 14653 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.588332 14653 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 1 LEADER]: Becoming Leader. State: Replica: 3c5dc9a4a9af47c29efa291ab678e470, State: Running, Role: LEADER
I20260812 06:19:43.588435 14647 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:43.588506 14653 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [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: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER }
I20260812 06:19:43.589046 14654 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3c5dc9a4a9af47c29efa291ab678e470" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER } }
I20260812 06:19:43.589144 14655 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3c5dc9a4a9af47c29efa291ab678e470. Latest consensus state: current_term: 1 leader_uuid: "3c5dc9a4a9af47c29efa291ab678e470" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5dc9a4a9af47c29efa291ab678e470" member_type: VOTER } }
I20260812 06:19:43.589154 14654 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.589326 14655 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.589730 14666 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:43.590555 14666 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:43.590731 14217 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:43.592378 14666 catalog_manager.cc:1383] Generated new cluster ID: 6662c29dd26b4d6e9a8cc263336be854
I20260812 06:19:43.592432 14666 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:43.606163 14666 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:43.606673 14666 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:43.621112 14666 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470: Generated new TSK 0
I20260812 06:19:43.621296 14666 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:43.623072 14217 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.624960 14683 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.625064 14217 server_base.cc:1061] running on GCE node
W20260812 06:19:43.624974 14685 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.624992 14688 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.625353 14217 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.625399 14217 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.625413 14217 hybrid_clock.cc:648] HybridClock initialized: now 1786515583625414 us; error 0 us; skew 500 ppm
I20260812 06:19:43.626194 14217 webserver.cc:533] Webserver started at http://127.13.226.65:36255/ using document root <none> and password file <none>
I20260812 06:19:43.626344 14217 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.626394 14217 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.626467 14217 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.626823 14217 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/instance:
uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-21b9"
I20260812 06:19:43.628268 14217 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:43.629175 14695 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.629422 14217 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:43.629494 14217 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root
uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-21b9"
I20260812 06:19:43.629549 14217 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.640260 14217 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.640606 14217 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.640854 14217 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:43.641296 14217 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:43.641335 14217 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.641371 14217 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:43.641398 14217 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.645323 14217 rpc_server.cc:307] RPC server started. Bound to: 127.13.226.65:39893
I20260812 06:19:43.645840 14801 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.226.65:39893 every 8 connection(s)
I20260812 06:19:43.652783 14803 heartbeater.cc:344] Connected to a master server at 127.13.226.126:43757
I20260812 06:19:43.652897 14803 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:43.653121 14803 heartbeater.cc:507] Master 127.13.226.126:43757 requested a full tablet report, sending...
I20260812 06:19:43.653736 14589 ts_manager.cc:194] Registered new tserver with Master: 46ba1cf40b8344dcb28f2cc5db39dc6e (127.13.226.65:39893)
I20260812 06:19:43.654409 14589 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33410
I20260812 06:19:43.654596 14217 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008777974s
I20260812 06:19:43.661240 14589 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33426:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:43.670046 14742 tablet_service.cc:1511] Processing CreateTablet for tablet 9af98e573371409ea02eae50a2e470f5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ced412a7762649c3988ce14e42f6f97f]), partition=
I20260812 06:19:43.670302 14742 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9af98e573371409ea02eae50a2e470f5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.672400 14821 tablet_bootstrap.cc:492] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Bootstrap starting.
I20260812 06:19:43.673280 14821 tablet_bootstrap.cc:654] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.674369 14821 tablet_bootstrap.cc:492] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: No bootstrap required, opened a new log
I20260812 06:19:43.674502 14821 ts_tablet_manager.cc:1403] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:43.674993 14821 raft_consensus.cc:359] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 39893 } }
I20260812 06:19:43.675107 14821 raft_consensus.cc:385] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.675176 14821 raft_consensus.cc:740] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 46ba1cf40b8344dcb28f2cc5db39dc6e, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.675318 14821 consensus_queue.cc:260] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [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: "46ba1cf40b8344dcb28f2cc5db39dc6e" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 39893 } }
I20260812 06:19:43.675407 14821 raft_consensus.cc:399] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.675436 14821 raft_consensus.cc:493] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.675477 14821 raft_consensus.cc:3060] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.676124 14821 raft_consensus.cc:515] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 39893 } }
I20260812 06:19:43.676239 14821 leader_election.cc:304] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [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: 46ba1cf40b8344dcb28f2cc5db39dc6e; no voters: 
I20260812 06:19:43.676378 14821 leader_election.cc:290] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.676509 14824 raft_consensus.cc:2804] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.676702 14824 raft_consensus.cc:697] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 1 LEADER]: Becoming Leader. State: Replica: 46ba1cf40b8344dcb28f2cc5db39dc6e, State: Running, Role: LEADER
I20260812 06:19:43.676720 14821 ts_tablet_manager.cc:1434] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:43.676755 14803 heartbeater.cc:499] Master 127.13.226.126:43757 was elected leader, sending a full tablet report...
I20260812 06:19:43.676851 14824 consensus_queue.cc:237] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [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: "46ba1cf40b8344dcb28f2cc5db39dc6e" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 39893 } }
I20260812 06:19:43.678138 14589 catalog_manager.cc:5719] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e reported cstate change: term changed from 0 to 1, leader changed from <none> to 46ba1cf40b8344dcb28f2cc5db39dc6e (127.13.226.65). New cstate: current_term: 1 leader_uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46ba1cf40b8344dcb28f2cc5db39dc6e" member_type: VOTER last_known_addr { host: "127.13.226.65" port: 39893 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:43.736058 14217 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.004s
I20260812 06:19:43.896293 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushMRSOp(9af98e573371409ea02eae50a2e470f5): perf score=23.023690
I20260812 06:19:44.056877 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushMRSOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.160s	user 0.118s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":870,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43128,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:44.057612 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling LogGCOp(9af98e573371409ea02eae50a2e470f5): free 20743880 bytes of WAL
I20260812 06:19:44.057863 14704 log_reader.cc:385] T 9af98e573371409ea02eae50a2e470f5: removed 2 log segments from log reader
I20260812 06:19:44.057924 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000001 (ops 1-6)
I20260812 06:19:44.057964 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000002 (ops 7-11)
I20260812 06:19:44.062585 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: LogGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:44.062955 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:44.076639 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.077160 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:44.215556 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.138s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":10028,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24100,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":314,"threads_started":5,"update_count":2000}
I20260812 06:19:44.216122 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5): 20513815 bytes on disk
I20260812 06:19:44.216576 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.217048 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:44.255950 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.039s	user 0.020s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12720,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.256453 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:44.272214 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.272794 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:44.418081 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.145s	user 0.117s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":10644,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23637,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.418560 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:44.461544 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.043s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15687,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.462023 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:44.472651 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.473249 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:44.591677 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.118s	user 0.086s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":8110,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21176,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:44.592191 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:44.632908 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.041s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.633472 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:44.644337 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.644855 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:44.778635 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.133s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":913,"lbm_read_time_us":9763,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26473,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2000}
I20260812 06:19:44.779112 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:44.823112 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.044s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.823570 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:44.833961 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3890,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.834390 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:44.963043 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.128s	user 0.116s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":8255,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25225,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43008,"update_count":2000}
I20260812 06:19:44.963675 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:45.016697 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.053s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.017354 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.033233 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.033784 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:45.175009 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.141s	user 0.097s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":663,"lbm_read_time_us":10740,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20993,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:45.175555 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:45.217424 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.042s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18101,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.217909 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.232165 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.232821 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushMRSOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:45.261025 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushMRSOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.028s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1465,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:45.261667 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling LogGCOp(9af98e573371409ea02eae50a2e470f5): free 112692363 bytes of WAL
I20260812 06:19:45.261893 14704 log_reader.cc:385] T 9af98e573371409ea02eae50a2e470f5: removed 11 log segments from log reader
I20260812 06:19:45.261946 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000003 (ops 12-16)
I20260812 06:19:45.261983 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000004 (ops 17-21)
I20260812 06:19:45.262017 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000005 (ops 22-26)
I20260812 06:19:45.262048 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000006 (ops 27-31)
I20260812 06:19:45.262079 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000007 (ops 32-36)
I20260812 06:19:45.262109 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000008 (ops 37-41)
I20260812 06:19:45.262140 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000009 (ops 42-46)
I20260812 06:19:45.262171 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000010 (ops 47-51)
I20260812 06:19:45.262200 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000011 (ops 52-56)
I20260812 06:19:45.262231 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000012 (ops 57-61)
I20260812 06:19:45.262262 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000013 (ops 62-66)
I20260812 06:19:45.282061 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: LogGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:45.282483 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5): 447 bytes on disk
I20260812 06:19:45.282899 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.283522 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=3.181125
I20260812 06:19:45.311484 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.028s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6304,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:45.312014 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.321576 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3431,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.322106 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:45.517025 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.195s	user 0.139s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":185,"lbm_read_time_us":14193,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31180,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:19:45.517606 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=14.095187
I20260812 06:19:45.575608 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.058s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21804,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.576200 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.586619 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.587045 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:45.758909 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.172s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":11828,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28442,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:45.759486 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=11.118625
I20260812 06:19:45.793630 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.034s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14337,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.794188 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.808393 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.808842 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:45.929776 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.121s	user 0.098s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":67,"lbm_read_time_us":6828,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20607,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.930330 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:45.962286 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.031s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12974,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.962816 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:45.979107 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.979756 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.118491 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.138s	user 0.103s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":123,"lbm_read_time_us":9997,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26458,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:19:46.119122 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:46.156736 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.037s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13723,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.157244 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:46.167342 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.167824 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.284968 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.117s	user 0.104s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":8294,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22960,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:46.285817 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:46.331876 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.045s	user 0.018s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16018,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.332407 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:46.342621 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.343142 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.491991 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.149s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":10178,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24695,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.492637 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:46.531157 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.038s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.531695 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:46.542618 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.543351 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.668517 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.125s	user 0.109s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":9512,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23086,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:19:46.669139 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:46.715394 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.046s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15919,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.715952 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:46.726668 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.727190 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushMRSOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.756275 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushMRSOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.029s	user 0.022s	sys 0.006s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1317,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1499,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:46.756938 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling LogGCOp(9af98e573371409ea02eae50a2e470f5): free 136728237 bytes of WAL
I20260812 06:19:46.757184 14704 log_reader.cc:385] T 9af98e573371409ea02eae50a2e470f5: removed 13 log segments from log reader
I20260812 06:19:46.757241 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000014 (ops 67-71)
I20260812 06:19:46.757287 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000015 (ops 72-76)
I20260812 06:19:46.757320 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000016 (ops 77-81)
I20260812 06:19:46.757341 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000017 (ops 82-86)
I20260812 06:19:46.757369 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000018 (ops 87-91)
I20260812 06:19:46.757395 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000019 (ops 92-96)
I20260812 06:19:46.757426 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000020 (ops 97-101)
I20260812 06:19:46.757457 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000021 (ops 102-106)
I20260812 06:19:46.757488 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000022 (ops 107-111)
I20260812 06:19:46.757515 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000023 (ops 112-116)
I20260812 06:19:46.757543 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000024 (ops 117-121)
I20260812 06:19:46.757567 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000025 (ops 122-126)
I20260812 06:19:46.757598 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000026 (ops 127-131)
I20260812 06:19:46.784755 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: LogGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:46.785128 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=3.181125
I20260812 06:19:46.796852 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:46.797309 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5): 481 bytes on disk
I20260812 06:19:46.797711 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.798244 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:46.808022 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3482,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.808568 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:46.979697 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.171s	user 0.137s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918320,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3813,"lbm_read_time_us":11913,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34923,"lbm_writes_lt_1ms":643,"mutex_wait_us":2785,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:46.980300 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=14.095187
I20260812 06:19:47.031827 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.051s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20920,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.032408 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:47.043490 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.043936 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:47.203329 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.159s	user 0.122s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":10081,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27168,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:47.203938 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=14.095187
I20260812 06:19:47.247608 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19139,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.248080 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:47.381765 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.134s	user 0.096s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":235,"lbm_read_time_us":8108,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21889,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:19:47.382253 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=11.118625
I20260812 06:19:47.418334 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15374,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:47.418921 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:47.435105 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5335,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.435714 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:47.561770 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.126s	user 0.103s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":8914,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23290,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:47.562325 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:47.590292 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.028s	user 0.022s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":11917,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.590786 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:47.601465 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.602175 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:47.724862 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.122s	user 0.100s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":8327,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22487,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2000}
I20260812 06:19:47.725345 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:47.762837 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.037s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13494,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.763372 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:47.773099 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.773540 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:47.889220 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.116s	user 0.086s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":8617,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22993,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:19:47.889932 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:47.930099 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.040s	user 0.007s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12718,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.930728 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:47.942310 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.942888 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:48.092935 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.150s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":106,"lbm_read_time_us":11749,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24244,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:48.094003 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=10.126437
I20260812 06:19:48.133379 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.039s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18191,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.133966 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:48.152005 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.018s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.152523 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushMRSOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:48.201874 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushMRSOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.049s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1597,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":768}
I20260812 06:19:48.202726 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling LogGCOp(9af98e573371409ea02eae50a2e470f5): free 124257506 bytes of WAL
I20260812 06:19:48.202965 14704 log_reader.cc:385] T 9af98e573371409ea02eae50a2e470f5: removed 12 log segments from log reader
I20260812 06:19:48.203013 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000027 (ops 132-136)
I20260812 06:19:48.203052 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000028 (ops 137-141)
I20260812 06:19:48.203085 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000029 (ops 142-146)
I20260812 06:19:48.203116 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000030 (ops 147-151)
I20260812 06:19:48.203147 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000031 (ops 152-156)
I20260812 06:19:48.203177 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000032 (ops 157-161)
I20260812 06:19:48.203208 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000033 (ops 162-166)
I20260812 06:19:48.203238 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000034 (ops 167-171)
I20260812 06:19:48.203300 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000035 (ops 172-176)
I20260812 06:19:48.203332 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000036 (ops 177-181)
I20260812 06:19:48.203356 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000037 (ops 182-186)
I20260812 06:19:48.203387 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000038 (ops 187-190)
I20260812 06:19:48.226888 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: LogGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.024s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:19:48.227648 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5): 493 bytes on disk
I20260812 06:19:48.228830 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: UndoDeltaBlockGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.229506 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=7.149875
I20260812 06:19:48.249293 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8234,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:48.249723 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling LogGCOp(9af98e573371409ea02eae50a2e470f5): free 8767088 bytes of WAL
I20260812 06:19:48.249917 14704 log_reader.cc:385] T 9af98e573371409ea02eae50a2e470f5: removed 1 log segments from log reader
I20260812 06:19:48.249963 14704 log.cc:1079] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: Deleting log segment in path: /tmp/dist-test-task0pRvIV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578395984-14217-0/minicluster-data/ts-0-root/wals/9af98e573371409ea02eae50a2e470f5/wal-000000039 (ops 191-195)
I20260812 06:19:48.251341 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: LogGCOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.001s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:48.251616 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5): perf score=2.188937
I20260812 06:19:48.261133 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: FlushDeltaMemStoresOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3404,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.261698 14805 maintenance_manager.cc:419] P 46ba1cf40b8344dcb28f2cc5db39dc6e: Scheduling MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5): perf score=1.000000
I20260812 06:19:48.342566 14217 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.606s	user 1.729s	sys 0.125s
I20260812 06:19:48.436106 14217 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.002s	sys 0.000s
I20260812 06:19:48.436594 14217 tablet_server.cc:179] TabletServer@127.13.226.65:0 shutting down...
I20260812 06:19:48.457072 14704 maintenance_manager.cc:643] P 46ba1cf40b8344dcb28f2cc5db39dc6e: MajorDeltaCompactionOp(9af98e573371409ea02eae50a2e470f5) complete. Timing: real 0.195s	user 0.143s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":616,"lbm_read_time_us":15765,"lbm_reads_lt_1ms":770,"lbm_write_time_us":29795,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17024,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:19:48.457933 14217 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:48.458272 14217 tablet_replica.cc:333] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e: stopping tablet replica
I20260812 06:19:48.458408 14217 raft_consensus.cc:2243] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.458559 14217 raft_consensus.cc:2272] T 9af98e573371409ea02eae50a2e470f5 P 46ba1cf40b8344dcb28f2cc5db39dc6e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.474385 14217 tablet_server.cc:196] TabletServer@127.13.226.65:0 shutdown complete.
I20260812 06:19:48.513160 14217 master.cc:562] Master@127.13.226.126:43757 shutting down...
I20260812 06:19:48.516146 14217 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.516315 14217 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.516397 14217 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3c5dc9a4a9af47c29efa291ab678e470: stopping tablet replica
I20260812 06:19:48.528501 14217 master.cc:584] Master@127.13.226.126:43757 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5048 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10189 ms total)

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