[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:51.778167  1253 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.57.126:38879
I20260812 06:16:51.779201  1253 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:51.779769  1253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:51.786018  1261 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:51.786062  1258 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:51.786209  1253 server_base.cc:1061] running on GCE node
W20260812 06:16:51.786304  1259 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:51.786823  1253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:51.786978  1253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:51.787014  1253 hybrid_clock.cc:648] HybridClock initialized: now 1786515411787011 us; error 0 us; skew 500 ppm
I20260812 06:16:51.788797  1253 webserver.cc:533] Webserver started at http://127.1.57.126:46257/ using document root <none> and password file <none>
I20260812 06:16:51.789331  1253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:51.789390  1253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:51.789582  1253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:51.791234  1253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/master-0-root/instance:
uuid: "7099ea380d754da78433bc75a53f0a2e"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-7c35"
I20260812 06:16:51.794425  1253 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:16:51.796415  1266 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:51.797336  1253 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:51.797470  1253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/master-0-root
uuid: "7099ea380d754da78433bc75a53f0a2e"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-7c35"
I20260812 06:16:51.797588  1253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:51.823167  1253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:51.823939  1253 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:51.824128  1253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:51.832188  1345 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.57.126:38879 every 8 connection(s)
I20260812 06:16:51.832204  1253 rpc_server.cc:307] RPC server started. Bound to: 127.1.57.126:38879
I20260812 06:16:51.834713  1346 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:51.840512  1346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: Bootstrap starting.
I20260812 06:16:51.843088  1346 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:51.844091  1346 log.cc:826] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:51.845881  1346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: No bootstrap required, opened a new log
I20260812 06:16:51.848703  1346 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER }
I20260812 06:16:51.848874  1346 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:51.849013  1346 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7099ea380d754da78433bc75a53f0a2e, State: Initialized, Role: FOLLOWER
I20260812 06:16:51.849644  1346 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [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: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER }
I20260812 06:16:51.849823  1346 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:51.849925  1346 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:51.850093  1346 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:51.851071  1346 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER }
I20260812 06:16:51.851536  1346 leader_election.cc:304] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [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: 7099ea380d754da78433bc75a53f0a2e; no voters: 
I20260812 06:16:51.851917  1346 leader_election.cc:290] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:51.852139  1352 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:51.852414  1352 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 1 LEADER]: Becoming Leader. State: Replica: 7099ea380d754da78433bc75a53f0a2e, State: Running, Role: LEADER
I20260812 06:16:51.852852  1352 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [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: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER }
I20260812 06:16:51.853077  1346 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:51.854930  1354 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7099ea380d754da78433bc75a53f0a2e. Latest consensus state: current_term: 1 leader_uuid: "7099ea380d754da78433bc75a53f0a2e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER } }
I20260812 06:16:51.854887  1353 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7099ea380d754da78433bc75a53f0a2e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7099ea380d754da78433bc75a53f0a2e" member_type: VOTER } }
I20260812 06:16:51.855044  1353 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:51.855044  1354 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:51.855420  1367 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:51.855705  1253 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:51.857744  1367 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:51.862406  1367 catalog_manager.cc:1383] Generated new cluster ID: 384c22b9e88244aca3128c4b3cd651b8
I20260812 06:16:51.862475  1367 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:51.869549  1367 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:51.870658  1367 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:51.885679  1367 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: Generated new TSK 0
I20260812 06:16:51.886443  1367 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:51.888603  1253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:51.891129  1378 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:51.891158  1379 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:51.891163  1381 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:51.891597  1253 server_base.cc:1061] running on GCE node
I20260812 06:16:51.891764  1253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:51.891820  1253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:51.891866  1253 hybrid_clock.cc:648] HybridClock initialized: now 1786515411891865 us; error 0 us; skew 500 ppm
I20260812 06:16:51.892849  1253 webserver.cc:533] Webserver started at http://127.1.57.65:42183/ using document root <none> and password file <none>
I20260812 06:16:51.893030  1253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:51.893101  1253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:51.893177  1253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:51.893555  1253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/instance:
uuid: "b39ddb1c7f614ec2bac89c769112528e"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-7c35"
I20260812 06:16:51.895108  1253 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:51.896101  1387 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:51.896354  1253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:51.896426  1253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root
uuid: "b39ddb1c7f614ec2bac89c769112528e"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-7c35"
I20260812 06:16:51.896512  1253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:51.912987  1253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:51.913765  1253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:51.914275  1253 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:51.915290  1253 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:51.915361  1253 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:51.915403  1253 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:51.915458  1253 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:51.922144  1253 rpc_server.cc:307] RPC server started. Bound to: 127.1.57.65:39681
I20260812 06:16:51.922184  1471 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.57.65:39681 every 8 connection(s)
I20260812 06:16:51.937229  1472 heartbeater.cc:344] Connected to a master server at 127.1.57.126:38879
I20260812 06:16:51.937515  1472 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:51.937976  1472 heartbeater.cc:507] Master 127.1.57.126:38879 requested a full tablet report, sending...
I20260812 06:16:51.939417  1294 ts_manager.cc:194] Registered new tserver with Master: b39ddb1c7f614ec2bac89c769112528e (127.1.57.65:39681)
I20260812 06:16:51.939497  1253 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016699561s
I20260812 06:16:51.940670  1294 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60706
I20260812 06:16:51.949375  1294 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60714:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:51.962911  1421 tablet_service.cc:1511] Processing CreateTablet for tablet a8db98852edb46c48ee6e1515635dbe0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3b27f8a6bf3a4bd786150cca0e4d4734]), partition=
I20260812 06:16:51.963430  1421 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a8db98852edb46c48ee6e1515635dbe0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:51.965703  1486 tablet_bootstrap.cc:492] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Bootstrap starting.
I20260812 06:16:51.966746  1486 tablet_bootstrap.cc:654] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:51.967911  1486 tablet_bootstrap.cc:492] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: No bootstrap required, opened a new log
I20260812 06:16:51.968029  1486 ts_tablet_manager.cc:1403] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:51.968523  1486 raft_consensus.cc:359] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b39ddb1c7f614ec2bac89c769112528e" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39681 } }
I20260812 06:16:51.968658  1486 raft_consensus.cc:385] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:51.968750  1486 raft_consensus.cc:740] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b39ddb1c7f614ec2bac89c769112528e, State: Initialized, Role: FOLLOWER
I20260812 06:16:51.968966  1486 consensus_queue.cc:260] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [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: "b39ddb1c7f614ec2bac89c769112528e" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39681 } }
I20260812 06:16:51.969120  1486 raft_consensus.cc:399] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:51.969203  1486 raft_consensus.cc:493] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:51.969264  1486 raft_consensus.cc:3060] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:51.970027  1486 raft_consensus.cc:515] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b39ddb1c7f614ec2bac89c769112528e" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39681 } }
I20260812 06:16:51.970222  1486 leader_election.cc:304] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [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: b39ddb1c7f614ec2bac89c769112528e; no voters: 
I20260812 06:16:51.970476  1486 leader_election.cc:290] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:51.970577  1490 raft_consensus.cc:2804] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:51.970784  1490 raft_consensus.cc:697] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 1 LEADER]: Becoming Leader. State: Replica: b39ddb1c7f614ec2bac89c769112528e, State: Running, Role: LEADER
I20260812 06:16:51.970937  1486 ts_tablet_manager.cc:1434] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:51.971048  1490 consensus_queue.cc:237] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [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: "b39ddb1c7f614ec2bac89c769112528e" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39681 } }
I20260812 06:16:51.971215  1472 heartbeater.cc:499] Master 127.1.57.126:38879 was elected leader, sending a full tablet report...
I20260812 06:16:51.973786  1293 catalog_manager.cc:5719] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e reported cstate change: term changed from 0 to 1, leader changed from <none> to b39ddb1c7f614ec2bac89c769112528e (127.1.57.65). New cstate: current_term: 1 leader_uuid: "b39ddb1c7f614ec2bac89c769112528e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b39ddb1c7f614ec2bac89c769112528e" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39681 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:52.044329  1253 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.015s	sys 0.017s
I20260812 06:16:52.173317  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0): perf score=15.086190
I20260812 06:16:52.343307  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.170s	user 0.139s	sys 0.024s Metrics: {"bytes_written":13948456,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":279,"dirs.run_wall_time_us":1031,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40858,"lbm_writes_lt_1ms":707,"mutex_wait_us":1338,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":27264,"thread_start_us":140,"threads_started":1,"update_count":1700}
I20260812 06:16:52.344368  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:52.357540  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3364213,"delete_count":0,"lbm_write_time_us":4928,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:16:52.357999  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling LogGCOp(a8db98852edb46c48ee6e1515635dbe0): free 20743880 bytes of WAL
I20260812 06:16:52.358325  1395 log_reader.cc:385] T a8db98852edb46c48ee6e1515635dbe0: removed 2 log segments from log reader
I20260812 06:16:52.358449  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000001 (ops 1-6)
I20260812 06:16:52.358546  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000002 (ops 7-11)
I20260812 06:16:52.363829  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: LogGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:52.364161  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0): 12719216 bytes on disk
I20260812 06:16:52.364804  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.365206  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.196750
I20260812 06:16:52.376289  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:16:52.376803  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:52.554406  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.177s	user 0.111s	sys 0.053s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364524,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":598,"lbm_read_time_us":10786,"lbm_reads_lt_1ms":559,"lbm_write_time_us":26250,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":303,"threads_started":5,"update_count":2450}
I20260812 06:16:52.555032  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:52.612286  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.057s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23357,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.612810  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:52.624099  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.624683  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:52.773581  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.149s	user 0.101s	sys 0.048s 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":182,"lbm_read_time_us":8737,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32500,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:16:52.774186  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=10.126437
I20260812 06:16:52.806078  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.032s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13832,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:52.806555  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:52.826275  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.826959  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:52.943365  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.116s	user 0.087s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1754,"lbm_read_time_us":6905,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23295,"lbm_writes_lt_1ms":443,"mutex_wait_us":766,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:52.943992  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=10.126437
I20260812 06:16:52.978695  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.035s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14805,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:52.979220  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:52.995203  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.995713  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:53.114715  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.119s	user 0.106s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":645,"lbm_read_time_us":9381,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20513,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:16:53.115319  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=10.126437
I20260812 06:16:53.161696  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.046s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15731,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.162392  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:53.174451  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.175077  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:53.331851  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.157s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":801,"lbm_read_time_us":11578,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28964,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.332512  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=10.126437
I20260812 06:16:53.371076  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.038s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14914,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.371568  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:53.386570  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.387362  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:53.515180  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.128s	user 0.109s	sys 0.018s 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":664,"lbm_read_time_us":9748,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23148,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.515710  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=10.126437
I20260812 06:16:53.562623  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.047s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18265,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.563192  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:53.578725  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.579487  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:53.608421  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1361,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1619,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:53.609289  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling LogGCOp(a8db98852edb46c48ee6e1515635dbe0): free 112239330 bytes of WAL
I20260812 06:16:53.609583  1395 log_reader.cc:385] T a8db98852edb46c48ee6e1515635dbe0: removed 11 log segments from log reader
I20260812 06:16:53.609629  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000003 (ops 12-16)
I20260812 06:16:53.609661  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000004 (ops 17-20)
I20260812 06:16:53.609725  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000005 (ops 21-25)
I20260812 06:16:53.609764  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000006 (ops 26-30)
I20260812 06:16:53.609818  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000007 (ops 31-35)
I20260812 06:16:53.609858  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000008 (ops 36-40)
I20260812 06:16:53.609895  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000009 (ops 41-45)
I20260812 06:16:53.609933  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000010 (ops 46-50)
I20260812 06:16:53.609969  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000011 (ops 51-55)
I20260812 06:16:53.610010  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000012 (ops 56-60)
I20260812 06:16:53.610045  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000013 (ops 61-65)
I20260812 06:16:53.636009  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: LogGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:53.636488  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0): 462 bytes on disk
I20260812 06:16:53.637130  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:16:53.637718  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=3.181125
I20260812 06:16:53.652254  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:53.652791  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:53.662272  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3511,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:53.662717  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:53.840719  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.178s	user 0.122s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":221,"lbm_read_time_us":13390,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33521,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":99840,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:16:53.841238  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:53.887029  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.046s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20226,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.887691  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:53.899803  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.900455  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:54.052758  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.152s	user 0.140s	sys 0.005s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":549,"lbm_read_time_us":9940,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28186,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:16:54.053390  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:54.104887  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.051s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19892,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.105472  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:54.116724  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.117192  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:54.287017  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.170s	user 0.134s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":11470,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30431,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":71424,"update_count":2500}
I20260812 06:16:54.287678  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:54.329094  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17803,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.329751  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:54.468163  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.138s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":148,"lbm_read_time_us":8272,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22771,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.468909  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=11.118625
I20260812 06:16:54.500043  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.031s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12782,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:54.500680  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:54.524948  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.024s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4680,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:54.525511  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:54.540078  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.540632  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:54.719180  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.178s	user 0.116s	sys 0.049s 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":484,"lbm_read_time_us":11149,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29615,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:16:54.719899  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:54.768431  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.048s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.768904  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:54.780328  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.780896  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:54.953464  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.172s	user 0.141s	sys 0.024s 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":1400,"lbm_read_time_us":10845,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31576,"lbm_writes_lt_1ms":543,"mutex_wait_us":487,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:16:54.954164  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=11.118625
I20260812 06:16:54.989814  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.035s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15604,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:54.990377  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:55.005682  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:55.006110  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:55.030654  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.024s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1312,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1379,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":896}
I20260812 06:16:55.031322  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling LogGCOp(a8db98852edb46c48ee6e1515635dbe0): free 133024316 bytes of WAL
I20260812 06:16:55.031539  1395 log_reader.cc:385] T a8db98852edb46c48ee6e1515635dbe0: removed 13 log segments from log reader
I20260812 06:16:55.031581  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000014 (ops 66-70)
I20260812 06:16:55.031608  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000015 (ops 71-74)
I20260812 06:16:55.031625  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000016 (ops 75-79)
I20260812 06:16:55.031687  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000017 (ops 80-84)
I20260812 06:16:55.031714  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000018 (ops 85-89)
I20260812 06:16:55.031759  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000019 (ops 90-94)
I20260812 06:16:55.031787  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000020 (ops 95-99)
I20260812 06:16:55.031829  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000021 (ops 100-104)
I20260812 06:16:55.031868  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000022 (ops 105-109)
I20260812 06:16:55.031906  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000023 (ops 110-114)
I20260812 06:16:55.031944  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000024 (ops 115-119)
I20260812 06:16:55.031989  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000025 (ops 120-124)
I20260812 06:16:55.032027  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000026 (ops 125-129)
I20260812 06:16:55.058887  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: LogGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:16:55.059314  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=6.157687
I20260812 06:16:55.080874  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.021s	user 0.010s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8491,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.081420  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0): 482 bytes on disk
I20260812 06:16:55.081988  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:55.082500  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:55.291077  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.208s	user 0.162s	sys 0.037s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877214,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":219,"dirs.run_cpu_time_us":492,"dirs.run_wall_time_us":3637,"lbm_read_time_us":12204,"lbm_reads_lt_1ms":669,"lbm_write_time_us":37973,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:16:55.291857  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=15.087375
I20260812 06:16:55.349344  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.057s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":25381,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:16:55.349762  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:55.368546  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.019s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.368983  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:55.378371  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3623,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:55.378765  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:55.568786  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.190s	user 0.151s	sys 0.039s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":157,"lbm_read_time_us":13644,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34761,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":3000}
I20260812 06:16:55.569480  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:55.631325  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.062s	user 0.037s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.631917  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:55.649115  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6527,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.649708  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:55.825826  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.176s	user 0.103s	sys 0.062s 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":764,"lbm_read_time_us":11384,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30027,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":90496,"update_count":2500}
I20260812 06:16:55.826490  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:55.871657  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.045s	user 0.017s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.872185  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:55.896441  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.024s	user 0.004s	sys 0.018s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5658,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.897123  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.086747  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.189s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1174,"lbm_read_time_us":12073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32749,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:16:56.087245  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:56.144580  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.057s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.145040  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:56.156446  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.156910  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.328410  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.171s	user 0.117s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":848,"lbm_read_time_us":11415,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25879,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:16:56.329101  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=14.095187
I20260812 06:16:56.373499  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.044s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20376,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.374049  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:56.385965  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.386693  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.547829  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.161s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":825,"lbm_read_time_us":9834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30734,"lbm_writes_lt_1ms":543,"mutex_wait_us":426,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:56.548619  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=11.118625
I20260812 06:16:56.584749  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.036s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13209,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:56.585518  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:56.605650  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5272,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:56.606153  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=2.188937
I20260812 06:16:56.616271  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.616917  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.648542  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushMRSOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.031s	user 0.018s	sys 0.011s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1709,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:56.649264  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling LogGCOp(a8db98852edb46c48ee6e1515635dbe0): free 133024698 bytes of WAL
I20260812 06:16:56.649509  1395 log_reader.cc:385] T a8db98852edb46c48ee6e1515635dbe0: removed 13 log segments from log reader
I20260812 06:16:56.649555  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000027 (ops 130-134)
I20260812 06:16:56.649583  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000028 (ops 135-139)
I20260812 06:16:56.649643  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000029 (ops 140-144)
I20260812 06:16:56.649672  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000030 (ops 145-149)
I20260812 06:16:56.649713  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000031 (ops 150-154)
I20260812 06:16:56.649766  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000032 (ops 155-158)
I20260812 06:16:56.649803  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000033 (ops 159-163)
I20260812 06:16:56.649859  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000034 (ops 164-168)
I20260812 06:16:56.649902  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000035 (ops 169-173)
I20260812 06:16:56.649942  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000036 (ops 174-178)
I20260812 06:16:56.649982  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000037 (ops 179-183)
I20260812 06:16:56.650022  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000038 (ops 184-188)
I20260812 06:16:56.650060  1395 log.cc:1079] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/a8db98852edb46c48ee6e1515635dbe0/wal-000000039 (ops 189-193)
I20260812 06:16:56.678288  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: LogGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:56.678786  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0): 492 bytes on disk
I20260812 06:16:56.679320  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: UndoDeltaBlockGCOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.680626  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=5.165500
I20260812 06:16:56.708779  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {"bytes_written":6358991,"delete_count":0,"lbm_write_time_us":7518,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:16:56.709270  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.715175  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1846277,"delete_count":0,"lbm_write_time_us":1852,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:16:56.715572  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0): perf score=1.000000
I20260812 06:16:56.819722  1253 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.775s	user 1.861s	sys 0.108s
I20260812 06:16:56.926689  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: MajorDeltaCompactionOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.211s	user 0.171s	sys 0.040s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979805,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":149,"lbm_read_time_us":16198,"lbm_reads_lt_1ms":771,"lbm_write_time_us":37298,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11136,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:16:56.927402  1473 maintenance_manager.cc:419] P b39ddb1c7f614ec2bac89c769112528e: Scheduling FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0): perf score=6.157687
I20260812 06:16:56.928576  1253 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.004s	sys 0.000s
I20260812 06:16:56.929217  1253 tablet_server.cc:179] TabletServer@127.1.57.65:0 shutting down...
I20260812 06:16:56.968600  1395 maintenance_manager.cc:643] P b39ddb1c7f614ec2bac89c769112528e: FlushDeltaMemStoresOp(a8db98852edb46c48ee6e1515635dbe0) complete. Timing: real 0.041s	user 0.018s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9258,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:56.969323  1253 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:56.969729  1253 tablet_replica.cc:333] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e: stopping tablet replica
I20260812 06:16:56.969988  1253 raft_consensus.cc:2243] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:56.970239  1253 raft_consensus.cc:2272] T a8db98852edb46c48ee6e1515635dbe0 P b39ddb1c7f614ec2bac89c769112528e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:56.985342  1253 tablet_server.cc:196] TabletServer@127.1.57.65:0 shutdown complete.
I20260812 06:16:56.990059  1253 master.cc:562] Master@127.1.57.126:38879 shutting down...
I20260812 06:16:56.994561  1253 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:56.994752  1253 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:56.994850  1253 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7099ea380d754da78433bc75a53f0a2e: stopping tablet replica
I20260812 06:16:57.007356  1253 master.cc:584] Master@127.1.57.126:38879 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5311 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:57.100373  1253 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.57.126:43077
I20260812 06:16:57.100759  1253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:57.102922  1253 server_base.cc:1061] running on GCE node
W20260812 06:16:57.102813  1510 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:57.102810  1509 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:57.102897  1512 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:57.103312  1253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.103358  1253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:57.103372  1253 hybrid_clock.cc:648] HybridClock initialized: now 1786515417103372 us; error 0 us; skew 500 ppm
I20260812 06:16:57.104166  1253 webserver.cc:533] Webserver started at http://127.1.57.126:44285/ using document root <none> and password file <none>
I20260812 06:16:57.104287  1253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.104326  1253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.104374  1253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.104718  1253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/master-0-root/instance:
uuid: "b57eaec7662344328f406d0ac385c545"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-7c35"
I20260812 06:16:57.106092  1253 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:57.107048  1518 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.107306  1253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:57.107393  1253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/master-0-root
uuid: "b57eaec7662344328f406d0ac385c545"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-7c35"
I20260812 06:16:57.107460  1253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:57.120498  1253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.120796  1253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.124936  1253 rpc_server.cc:307] RPC server started. Bound to: 127.1.57.126:43077
I20260812 06:16:57.126003  1589 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.57.126:43077 every 8 connection(s)
I20260812 06:16:57.129092  1592 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:57.130762  1592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545: Bootstrap starting.
I20260812 06:16:57.131556  1592 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.132495  1592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545: No bootstrap required, opened a new log
I20260812 06:16:57.132906  1592 raft_consensus.cc:359] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b57eaec7662344328f406d0ac385c545" member_type: VOTER }
I20260812 06:16:57.132989  1592 raft_consensus.cc:385] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.133044  1592 raft_consensus.cc:740] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b57eaec7662344328f406d0ac385c545, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.133222  1592 consensus_queue.cc:260] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [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: "b57eaec7662344328f406d0ac385c545" member_type: VOTER }
I20260812 06:16:57.133293  1592 raft_consensus.cc:399] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.133335  1592 raft_consensus.cc:493] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.133392  1592 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.134048  1592 raft_consensus.cc:515] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b57eaec7662344328f406d0ac385c545" member_type: VOTER }
I20260812 06:16:57.134153  1592 leader_election.cc:304] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [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: b57eaec7662344328f406d0ac385c545; no voters: 
I20260812 06:16:57.134387  1592 leader_election.cc:290] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.134552  1596 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.134757  1596 raft_consensus.cc:697] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 1 LEADER]: Becoming Leader. State: Replica: b57eaec7662344328f406d0ac385c545, State: Running, Role: LEADER
I20260812 06:16:57.134868  1592 sys_catalog.cc:565] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:57.134935  1596 consensus_queue.cc:237] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [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: "b57eaec7662344328f406d0ac385c545" member_type: VOTER }
I20260812 06:16:57.135382  1597 sys_catalog.cc:455] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b57eaec7662344328f406d0ac385c545" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b57eaec7662344328f406d0ac385c545" member_type: VOTER } }
I20260812 06:16:57.135413  1598 sys_catalog.cc:455] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b57eaec7662344328f406d0ac385c545. Latest consensus state: current_term: 1 leader_uuid: "b57eaec7662344328f406d0ac385c545" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b57eaec7662344328f406d0ac385c545" member_type: VOTER } }
I20260812 06:16:57.135476  1597 sys_catalog.cc:458] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.135506  1598 sys_catalog.cc:458] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.135718  1604 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:57.136479  1604 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:57.136739  1253 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:57.138281  1604 catalog_manager.cc:1383] Generated new cluster ID: 3c7d7b8ae4904f369ebe095a08640d42
I20260812 06:16:57.138339  1604 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:57.147589  1604 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:57.148066  1604 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:57.156118  1604 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545: Generated new TSK 0
I20260812 06:16:57.156256  1604 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:57.168990  1253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:57.171037  1628 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:57.171037  1625 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:57.171164  1253 server_base.cc:1061] running on GCE node
W20260812 06:16:57.171072  1623 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:57.171396  1253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.171461  1253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:57.171514  1253 hybrid_clock.cc:648] HybridClock initialized: now 1786515417171512 us; error 0 us; skew 500 ppm
I20260812 06:16:57.172380  1253 webserver.cc:533] Webserver started at http://127.1.57.65:36853/ using document root <none> and password file <none>
I20260812 06:16:57.172567  1253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.172638  1253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.172713  1253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.173127  1253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/instance:
uuid: "dc3ab1da173e46e28af6f76204adca75"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-7c35"
I20260812 06:16:57.174638  1253 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:57.175608  1636 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.175817  1253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.175904  1253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root
uuid: "dc3ab1da173e46e28af6f76204adca75"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-7c35"
I20260812 06:16:57.176000  1253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:57.188022  1253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.188334  1253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.188611  1253 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:57.189054  1253 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:57.189111  1253 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.189186  1253 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:57.189236  1253 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.193568  1253 rpc_server.cc:307] RPC server started. Bound to: 127.1.57.65:39965
I20260812 06:16:57.194891  1721 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.57.65:39965 every 8 connection(s)
I20260812 06:16:57.206202  1722 heartbeater.cc:344] Connected to a master server at 127.1.57.126:43077
I20260812 06:16:57.206286  1722 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:57.206524  1722 heartbeater.cc:507] Master 127.1.57.126:43077 requested a full tablet report, sending...
I20260812 06:16:57.207190  1544 ts_manager.cc:194] Registered new tserver with Master: dc3ab1da173e46e28af6f76204adca75 (127.1.57.65:39965)
I20260812 06:16:57.207707  1253 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013315592s
I20260812 06:16:57.207924  1544 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43540
I20260812 06:16:57.214248  1544 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43546:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:57.223083  1677 tablet_service.cc:1511] Processing CreateTablet for tablet 99720e6d4f5041edaf232213405b82fc (DEFAULT_TABLE table=heavy-update-compaction-test [id=e3dd1059bed54e5b9e0c6a0bc6357558]), partition=
I20260812 06:16:57.223374  1677 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 99720e6d4f5041edaf232213405b82fc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:57.225303  1738 tablet_bootstrap.cc:492] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Bootstrap starting.
I20260812 06:16:57.226155  1738 tablet_bootstrap.cc:654] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.227234  1738 tablet_bootstrap.cc:492] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: No bootstrap required, opened a new log
I20260812 06:16:57.227348  1738 ts_tablet_manager.cc:1403] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:57.227826  1738 raft_consensus.cc:359] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc3ab1da173e46e28af6f76204adca75" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39965 } }
I20260812 06:16:57.227939  1738 raft_consensus.cc:385] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.227984  1738 raft_consensus.cc:740] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dc3ab1da173e46e28af6f76204adca75, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.228178  1738 consensus_queue.cc:260] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [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: "dc3ab1da173e46e28af6f76204adca75" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39965 } }
I20260812 06:16:57.228289  1738 raft_consensus.cc:399] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.228338  1738 raft_consensus.cc:493] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.228402  1738 raft_consensus.cc:3060] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.229146  1738 raft_consensus.cc:515] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc3ab1da173e46e28af6f76204adca75" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39965 } }
I20260812 06:16:57.229303  1738 leader_election.cc:304] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [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: dc3ab1da173e46e28af6f76204adca75; no voters: 
I20260812 06:16:57.229539  1738 leader_election.cc:290] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.229660  1741 raft_consensus.cc:2804] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.229907  1738 ts_tablet_manager.cc:1434] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:57.229954  1722 heartbeater.cc:499] Master 127.1.57.126:43077 was elected leader, sending a full tablet report...
I20260812 06:16:57.229907  1741 raft_consensus.cc:697] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 1 LEADER]: Becoming Leader. State: Replica: dc3ab1da173e46e28af6f76204adca75, State: Running, Role: LEADER
I20260812 06:16:57.230178  1741 consensus_queue.cc:237] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [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: "dc3ab1da173e46e28af6f76204adca75" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39965 } }
I20260812 06:16:57.231577  1544 catalog_manager.cc:5719] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 reported cstate change: term changed from 0 to 1, leader changed from <none> to dc3ab1da173e46e28af6f76204adca75 (127.1.57.65). New cstate: current_term: 1 leader_uuid: "dc3ab1da173e46e28af6f76204adca75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc3ab1da173e46e28af6f76204adca75" member_type: VOTER last_known_addr { host: "127.1.57.65" port: 39965 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.290696  1253 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.011s	sys 0.012s
I20260812 06:16:57.445241  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushMRSOp(99720e6d4f5041edaf232213405b82fc): perf score=23.023690
I20260812 06:16:57.596033  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushMRSOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.151s	user 0.117s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":964,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40426,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:16:57.596685  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling LogGCOp(99720e6d4f5041edaf232213405b82fc): free 20743880 bytes of WAL
I20260812 06:16:57.596920  1644 log_reader.cc:385] T 99720e6d4f5041edaf232213405b82fc: removed 2 log segments from log reader
I20260812 06:16:57.596982  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000001 (ops 1-6)
I20260812 06:16:57.597021  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000002 (ops 7-11)
I20260812 06:16:57.602056  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: LogGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:57.602396  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:57.620316  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.620958  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc): 20513814 bytes on disk
I20260812 06:16:57.621430  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.621872  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:57.749850  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.128s	user 0.088s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":985,"lbm_read_time_us":9309,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23010,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":373,"threads_started":5,"update_count":2000}
I20260812 06:16:57.750633  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=10.126437
I20260812 06:16:57.788159  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.037s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15244,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.788626  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:57.800776  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4409,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.801160  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:57.957608  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.156s	user 0.105s	sys 0.047s 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":269,"lbm_read_time_us":12234,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23784,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:57.958200  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=11.118625
I20260812 06:16:57.999271  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.041s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15142,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:57.999806  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:58.010612  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.011025  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:58.027906  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3413,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.028379  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:58.226902  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.198s	user 0.130s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":583,"lbm_read_time_us":14000,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28985,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:16:58.227672  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:16:58.281512  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.054s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23989,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.282004  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:58.293869  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.294307  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:58.470892  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.176s	user 0.114s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":427,"lbm_read_time_us":10689,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25945,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:16:58.471618  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:16:58.516551  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.045s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.517066  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:58.531272  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5597,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.531664  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:58.673138  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.141s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":434,"lbm_read_time_us":10073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26674,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:16:58.673733  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=11.118625
I20260812 06:16:58.708616  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.035s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14803,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.709259  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:58.724581  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.725123  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushMRSOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:58.763026  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushMRSOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.038s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1387,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1543,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:58.763782  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling LogGCOp(99720e6d4f5041edaf232213405b82fc): free 112239306 bytes of WAL
I20260812 06:16:58.764016  1644 log_reader.cc:385] T 99720e6d4f5041edaf232213405b82fc: removed 11 log segments from log reader
I20260812 06:16:58.764061  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000003 (ops 12-16)
I20260812 06:16:58.764091  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000004 (ops 17-21)
I20260812 06:16:58.764159  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000005 (ops 22-26)
I20260812 06:16:58.764213  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000006 (ops 27-31)
I20260812 06:16:58.764253  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000007 (ops 32-36)
I20260812 06:16:58.764294  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000008 (ops 37-41)
I20260812 06:16:58.764329  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000009 (ops 42-46)
I20260812 06:16:58.764370  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000010 (ops 47-50)
I20260812 06:16:58.764410  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000011 (ops 51-55)
I20260812 06:16:58.764447  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000012 (ops 56-60)
I20260812 06:16:58.764496  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000013 (ops 61-65)
I20260812 06:16:58.787168  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: LogGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.023s	user 0.001s	sys 0.022s Metrics: {}
I20260812 06:16:58.787664  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=6.157687
I20260812 06:16:58.817662  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.030s	user 0.021s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12367,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:58.818277  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc): 447 bytes on disk
I20260812 06:16:58.818670  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.819229  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:59.016719  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.197s	user 0.125s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918207,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1065,"lbm_read_time_us":11581,"lbm_reads_lt_1ms":665,"lbm_write_time_us":31289,"lbm_writes_lt_1ms":643,"mutex_wait_us":464,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:16:59.017483  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=18.063937
I20260812 06:16:59.083340  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.066s	user 0.022s	sys 0.043s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":24505,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.083942  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.095477  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4464,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.095891  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:59.295904  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.200s	user 0.132s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":79,"lbm_read_time_us":15426,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32596,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":3000}
I20260812 06:16:59.296813  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:16:59.357160  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.060s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.357659  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.387051  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.029s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.387534  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.397670  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.398200  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:59.600196  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.202s	user 0.127s	sys 0.070s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":167,"lbm_read_time_us":13599,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33074,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3000}
I20260812 06:16:59.600800  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=15.087375
I20260812 06:16:59.653761  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22513,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:59.654325  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.676306  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.022s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.676793  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.686594  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.687041  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:16:59.888603  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.201s	user 0.122s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":172,"lbm_read_time_us":12379,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31724,"lbm_writes_lt_1ms":643,"mutex_wait_us":64,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3000}
I20260812 06:16:59.889145  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=18.063937
I20260812 06:16:59.959510  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.070s	user 0.032s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29419,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.959913  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:16:59.970384  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.970831  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:00.179193  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.208s	user 0.148s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":14115,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36620,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":3000}
I20260812 06:17:00.179845  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:17:00.226581  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20649,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.227382  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:00.245074  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":500}
I20260812 06:17:00.245584  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushMRSOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:00.300386  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushMRSOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.055s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1332,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:00.301038  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling LogGCOp(99720e6d4f5041edaf232213405b82fc): free 124710247 bytes of WAL
I20260812 06:17:00.301265  1644 log_reader.cc:385] T 99720e6d4f5041edaf232213405b82fc: removed 12 log segments from log reader
I20260812 06:17:00.301307  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000014 (ops 66-70)
I20260812 06:17:00.301335  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000015 (ops 71-75)
I20260812 06:17:00.301398  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000016 (ops 76-80)
I20260812 06:17:00.301431  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000017 (ops 81-85)
I20260812 06:17:00.301481  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000018 (ops 86-90)
I20260812 06:17:00.301512  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000019 (ops 91-95)
I20260812 06:17:00.301569  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000020 (ops 96-100)
I20260812 06:17:00.301610  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000021 (ops 101-105)
I20260812 06:17:00.301649  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000022 (ops 106-110)
I20260812 06:17:00.301687  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000023 (ops 111-115)
I20260812 06:17:00.301725  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000024 (ops 116-120)
I20260812 06:17:00.301764  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000025 (ops 121-125)
I20260812 06:17:00.328402  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: LogGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:00.328843  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc): 483 bytes on disk
I20260812 06:17:00.329463  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: UndoDeltaBlockGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.329965  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=7.149875
I20260812 06:17:00.352458  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.022s	user 0.016s	sys 0.005s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9458,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:00.352979  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling LogGCOp(99720e6d4f5041edaf232213405b82fc): free 8767182 bytes of WAL
I20260812 06:17:00.353209  1644 log_reader.cc:385] T 99720e6d4f5041edaf232213405b82fc: removed 1 log segments from log reader
I20260812 06:17:00.353269  1644 log.cc:1079] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: Deleting log segment in path: /tmp/dist-test-taskjmMRze/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411767509-1253-0/minicluster-data/ts-0-root/wals/99720e6d4f5041edaf232213405b82fc/wal-000000026 (ops 126-130)
I20260812 06:17:00.355494  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: LogGCOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:00.355794  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:00.369415  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4505,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.369886  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:00.616261  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.246s	user 0.159s	sys 0.078s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123150,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":264,"lbm_read_time_us":15530,"lbm_reads_lt_1ms":870,"lbm_write_time_us":42401,"lbm_writes_lt_1ms":843,"mutex_wait_us":28,"peak_mem_usage":100395616,"reinsert_count":0,"thread_start_us":73,"threads_started":1,"update_count":4000}
I20260812 06:17:00.616995  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=22.032687
I20260812 06:17:00.678438  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.061s	user 0.033s	sys 0.025s Metrics: {"bytes_written":24614719,"delete_count":0,"lbm_write_time_us":27703,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:17:00.678917  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:00.697896  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.698396  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:00.880443  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.182s	user 0.165s	sys 0.015s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020500,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":11632,"lbm_reads_lt_1ms":764,"lbm_write_time_us":37873,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3500}
I20260812 06:17:00.881114  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=15.087375
I20260812 06:17:00.927994  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.045s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":19245,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:00.928680  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:00.944773  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5467,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.945261  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:01.120337  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.175s	user 0.153s	sys 0.012s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815669,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1003,"lbm_read_time_us":10628,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35728,"lbm_writes_lt_1ms":543,"mutex_wait_us":414,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:17:01.123780  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:17:01.173264  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.049s	user 0.017s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21000,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.173787  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:01.184011  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.184474  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:01.362066  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.177s	user 0.113s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1086,"lbm_read_time_us":10749,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26621,"lbm_writes_lt_1ms":543,"mutex_wait_us":456,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:01.362823  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=14.095187
I20260812 06:17:01.428877  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.066s	user 0.043s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28570,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.429318  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=2.188937
I20260812 06:17:01.439714  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.440414  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc): perf score=1.000000
I20260812 06:17:01.665802  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: MajorDeltaCompactionOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.225s	user 0.133s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":727,"lbm_read_time_us":10945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27970,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:01.666651  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=18.063937
I20260812 06:17:01.760507  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.094s	user 0.048s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28491,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:01.761042  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=3.181125
I20260812 06:17:01.857457  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.096s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6163,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:01.858153  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=6.157687
I20260812 06:17:01.914538  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.056s	user 0.007s	sys 0.016s Metrics: {"bytes_written":8410199,"delete_count":0,"lbm_write_time_us":10252,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:17:01.915362  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=6.157687
I20260812 06:17:01.998998  1253 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.708s	user 1.791s	sys 0.130s
I20260812 06:17:02.015331  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.100s	user 0.016s	sys 0.000s Metrics: {"bytes_written":7589721,"delete_count":0,"lbm_write_time_us":7331,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:17:02.016026  1723 maintenance_manager.cc:419] P dc3ab1da173e46e28af6f76204adca75: Scheduling FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc): perf score=6.157687
I20260812 06:17:02.097748  1253 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.001s	sys 0.000s
I20260812 06:17:02.098276  1253 tablet_server.cc:179] TabletServer@127.1.57.65:0 shutting down...
I20260812 06:17:02.120533  1644 maintenance_manager.cc:643] P dc3ab1da173e46e28af6f76204adca75: FlushDeltaMemStoresOp(99720e6d4f5041edaf232213405b82fc) complete. Timing: real 0.104s	user 0.013s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9086,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1000}
I20260812 06:17:02.121245  1253 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:02.121505  1253 tablet_replica.cc:333] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75: stopping tablet replica
I20260812 06:17:02.121675  1253 raft_consensus.cc:2243] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.121851  1253 raft_consensus.cc:2272] T 99720e6d4f5041edaf232213405b82fc P dc3ab1da173e46e28af6f76204adca75 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.136622  1253 tablet_server.cc:196] TabletServer@127.1.57.65:0 shutdown complete.
I20260812 06:17:02.139576  1253 master.cc:562] Master@127.1.57.126:43077 shutting down...
I20260812 06:17:02.142887  1253 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.143074  1253 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.143155  1253 tablet_replica.cc:333] T 00000000000000000000000000000000 P b57eaec7662344328f406d0ac385c545: stopping tablet replica
I20260812 06:17:02.155503  1253 master.cc:584] Master@127.1.57.126:43077 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5173 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10486 ms total)

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