[==========] 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:56.896552  6965 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.205.126:42715
I20260812 06:16:56.897692  6965 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:56.898327  6965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.905575  6975 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:56.905644  6965 server_base.cc:1061] running on GCE node
W20260812 06:16:56.905587  6978 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:56.905851  6973 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:56.906390  6965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.906495  6965 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:56.906522  6965 hybrid_clock.cc:648] HybridClock initialized: now 1786515416906521 us; error 0 us; skew 500 ppm
I20260812 06:16:56.908427  6965 webserver.cc:533] Webserver started at http://127.6.205.126:34511/ using document root <none> and password file <none>
I20260812 06:16:56.909018  6965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.909094  6965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.909297  6965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.910905  6965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/master-0-root/instance:
uuid: "8aa2ecd9468e4f25af6278ba142f3e9f"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-3h5h"
I20260812 06:16:56.914618  6965 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:16:56.916728  6984 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:56.917873  6965 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:56.918025  6965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/master-0-root
uuid: "8aa2ecd9468e4f25af6278ba142f3e9f"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-3h5h"
I20260812 06:16:56.918143  6965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-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:56.934746  6965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.935448  6965 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:56.935640  6965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.943722  6965 rpc_server.cc:307] RPC server started. Bound to: 127.6.205.126:42715
I20260812 06:16:56.943751  7063 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.205.126:42715 every 8 connection(s)
I20260812 06:16:56.946115  7064 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:56.951550  7064 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: Bootstrap starting.
I20260812 06:16:56.953953  7064 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.954874  7064 log.cc:826] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:56.956516  7064 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: No bootstrap required, opened a new log
I20260812 06:16:56.959280  7064 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER }
I20260812 06:16:56.959439  7064 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.959488  7064 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8aa2ecd9468e4f25af6278ba142f3e9f, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.960018  7064 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [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: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER }
I20260812 06:16:56.960147  7064 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.960187  7064 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.960268  7064 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.961086  7064 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER }
I20260812 06:16:56.961468  7064 leader_election.cc:304] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [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: 8aa2ecd9468e4f25af6278ba142f3e9f; no voters: 
I20260812 06:16:56.961766  7064 leader_election.cc:290] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.961910  7067 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.962196  7067 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 1 LEADER]: Becoming Leader. State: Replica: 8aa2ecd9468e4f25af6278ba142f3e9f, State: Running, Role: LEADER
I20260812 06:16:56.962661  7067 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [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: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER }
I20260812 06:16:56.962827  7064 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:56.964552  7071 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8aa2ecd9468e4f25af6278ba142f3e9f. Latest consensus state: current_term: 1 leader_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER } }
I20260812 06:16:56.964586  7069 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa2ecd9468e4f25af6278ba142f3e9f" member_type: VOTER } }
I20260812 06:16:56.964677  7071 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.964694  7069 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.965106  7082 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:56.965305  6965 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:56.967408  7082 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:56.972399  7082 catalog_manager.cc:1383] Generated new cluster ID: 32f05c41413f48a08398dcc95d15f757
I20260812 06:16:56.972494  7082 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:56.987689  7082 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:56.988688  7082 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:56.999998  7082 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: Generated new TSK 0
I20260812 06:16:57.000815  7082 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:57.030869  6965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:57.034266  7104 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.034379  7101 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.034523  6965 server_base.cc:1061] running on GCE node
W20260812 06:16:57.034385  7107 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.034843  6965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.034906  6965 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.034934  6965 hybrid_clock.cc:648] HybridClock initialized: now 1786515417034933 us; error 0 us; skew 500 ppm
I20260812 06:16:57.036001  6965 webserver.cc:533] Webserver started at http://127.6.205.65:38169/ using document root <none> and password file <none>
I20260812 06:16:57.036252  6965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.036337  6965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.036427  6965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.036901  6965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/instance:
uuid: "c6acfbbd280a4ac79c03fdff47619121"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-3h5h"
I20260812 06:16:57.038559  6965 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.039618  7119 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.039868  6965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.039944  6965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root
uuid: "c6acfbbd280a4ac79c03fdff47619121"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-3h5h"
I20260812 06:16:57.040037  6965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-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.055013  6965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.055588  6965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.056167  6965 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:57.057649  6965 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:57.057709  6965 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.057790  6965 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:57.057833  6965 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.065585  6965 rpc_server.cc:307] RPC server started. Bound to: 127.6.205.65:37779
I20260812 06:16:57.065680  7232 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.205.65:37779 every 8 connection(s)
I20260812 06:16:57.079440  7233 heartbeater.cc:344] Connected to a master server at 127.6.205.126:42715
I20260812 06:16:57.079771  7233 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:57.080255  7233 heartbeater.cc:507] Master 127.6.205.126:42715 requested a full tablet report, sending...
I20260812 06:16:57.081986  7013 ts_manager.cc:194] Registered new tserver with Master: c6acfbbd280a4ac79c03fdff47619121 (127.6.205.65:37779)
I20260812 06:16:57.082242  6965 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015949882s
I20260812 06:16:57.083593  7013 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50916
I20260812 06:16:57.093091  7013 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50924:
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.107424  7165 tablet_service.cc:1511] Processing CreateTablet for tablet e11c7d74749241de8ab93fb9e06c85b5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7df92efaaf604cbf92accadea5aebf28]), partition=
I20260812 06:16:57.107894  7165 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e11c7d74749241de8ab93fb9e06c85b5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:57.110504  7258 tablet_bootstrap.cc:492] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Bootstrap starting.
I20260812 06:16:57.111500  7258 tablet_bootstrap.cc:654] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.113075  7258 tablet_bootstrap.cc:492] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: No bootstrap required, opened a new log
I20260812 06:16:57.113209  7258 ts_tablet_manager.cc:1403] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:57.113899  7258 raft_consensus.cc:359] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6acfbbd280a4ac79c03fdff47619121" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 37779 } }
I20260812 06:16:57.114140  7258 raft_consensus.cc:385] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.114225  7258 raft_consensus.cc:740] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c6acfbbd280a4ac79c03fdff47619121, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.114411  7258 consensus_queue.cc:260] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [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: "c6acfbbd280a4ac79c03fdff47619121" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 37779 } }
I20260812 06:16:57.114521  7258 raft_consensus.cc:399] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.114617  7258 raft_consensus.cc:493] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.114691  7258 raft_consensus.cc:3060] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.115500  7258 raft_consensus.cc:515] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6acfbbd280a4ac79c03fdff47619121" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 37779 } }
I20260812 06:16:57.115677  7258 leader_election.cc:304] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [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: c6acfbbd280a4ac79c03fdff47619121; no voters: 
I20260812 06:16:57.115931  7258 leader_election.cc:290] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.116025  7260 raft_consensus.cc:2804] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.116220  7260 raft_consensus.cc:697] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 1 LEADER]: Becoming Leader. State: Replica: c6acfbbd280a4ac79c03fdff47619121, State: Running, Role: LEADER
I20260812 06:16:57.116329  7258 ts_tablet_manager.cc:1434] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:57.116425  7260 consensus_queue.cc:237] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [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: "c6acfbbd280a4ac79c03fdff47619121" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 37779 } }
I20260812 06:16:57.116677  7233 heartbeater.cc:499] Master 127.6.205.126:42715 was elected leader, sending a full tablet report...
I20260812 06:16:57.119537  7013 catalog_manager.cc:5719] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 reported cstate change: term changed from 0 to 1, leader changed from <none> to c6acfbbd280a4ac79c03fdff47619121 (127.6.205.65). New cstate: current_term: 1 leader_uuid: "c6acfbbd280a4ac79c03fdff47619121" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6acfbbd280a4ac79c03fdff47619121" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 37779 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.188911  6965 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.017s	sys 0.012s
I20260812 06:16:57.316773  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=15.086190
I20260812 06:16:57.474990  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.158s	user 0.121s	sys 0.032s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":348,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":979,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37860,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":137,"threads_started":1,"update_count":1050}
I20260812 06:16:57.477304  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling LogGCOp(e11c7d74749241de8ab93fb9e06c85b5): free 20743880 bytes of WAL
I20260812 06:16:57.477633  7126 log_reader.cc:385] T e11c7d74749241de8ab93fb9e06c85b5: removed 2 log segments from log reader
I20260812 06:16:57.477718  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000001 (ops 1-6)
I20260812 06:16:57.477800  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000002 (ops 7-11)
I20260812 06:16:57.482446  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: LogGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:57.483002  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:57.499379  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5510,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.500097  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5): 16411392 bytes on disk
I20260812 06:16:57.500773  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5) 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:57.501397  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:57.612465  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.111s	user 0.090s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":664,"lbm_read_time_us":6243,"lbm_reads_lt_1ms":360,"lbm_write_time_us":19343,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":310,"threads_started":5,"update_count":1500}
I20260812 06:16:57.613062  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:57.659875  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.047s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.660318  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:57.670996  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.671517  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:57.819259  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.148s	user 0.119s	sys 0.023s 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":727,"lbm_read_time_us":9232,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26095,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:57.821138  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:57.872057  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.050s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18348,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.873190  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:57.883433  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.010s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1312956,"delete_count":0,"lbm_write_time_us":1446,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:16:57.884047  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.196750
I20260812 06:16:57.895277  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:16:57.895817  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.053330  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.157s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":233,"lbm_read_time_us":12691,"lbm_reads_lt_1ms":473,"lbm_write_time_us":23588,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":33920,"update_count":2000}
I20260812 06:16:58.054136  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:58.092283  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.038s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13601,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.092933  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.212734  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.120s	user 0.100s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":475,"lbm_read_time_us":6547,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23512,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.213514  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:58.259859  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.046s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20183,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.260331  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:58.271080  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.271598  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.402495  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.131s	user 0.098s	sys 0.026s 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":547,"lbm_read_time_us":7886,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23277,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:16:58.403136  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:58.459338  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.056s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.459878  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:58.470714  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.471266  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.620721  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.149s	user 0.113s	sys 0.036s 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":234,"lbm_read_time_us":10378,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24661,"lbm_writes_lt_1ms":443,"mutex_wait_us":83,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.621417  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:58.666371  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.045s	user 0.015s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16449,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.666862  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:58.677968  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.678674  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.815197  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.136s	user 0.108s	sys 0.028s 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":338,"lbm_read_time_us":8560,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27201,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:16:58.815869  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=10.126437
I20260812 06:16:58.862478  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.046s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22847,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.863080  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:58.875185  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.875666  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:58.910300  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.034s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1855,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1695,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:58.911190  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling LogGCOp(e11c7d74749241de8ab93fb9e06c85b5): free 121006436 bytes of WAL
I20260812 06:16:58.911468  7126 log_reader.cc:385] T e11c7d74749241de8ab93fb9e06c85b5: removed 12 log segments from log reader
I20260812 06:16:58.911533  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000003 (ops 12-16)
I20260812 06:16:58.911594  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000004 (ops 17-21)
I20260812 06:16:58.911651  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000005 (ops 22-26)
I20260812 06:16:58.911691  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000006 (ops 27-31)
I20260812 06:16:58.911727  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000007 (ops 32-36)
I20260812 06:16:58.911767  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000008 (ops 37-40)
I20260812 06:16:58.911803  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000009 (ops 41-45)
I20260812 06:16:58.911840  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000010 (ops 46-50)
I20260812 06:16:58.911876  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000011 (ops 51-55)
I20260812 06:16:58.911913  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000012 (ops 56-60)
I20260812 06:16:58.911949  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000013 (ops 61-65)
I20260812 06:16:58.911985  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000014 (ops 66-70)
I20260812 06:16:58.937991  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: LogGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:16:58.938429  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5): 472 bytes on disk
I20260812 06:16:58.938957  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5) 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:16:58.939556  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=3.181125
I20260812 06:16:58.958107  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4553933,"delete_count":0,"lbm_write_time_us":7208,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:16:58.958635  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:58.973299  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.014s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":5328,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:16:58.974048  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:59.160873  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.187s	user 0.144s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":816,"lbm_read_time_us":11647,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34823,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:16:59.162492  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:16:59.221437  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.059s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.221920  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:59.236375  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.237030  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:59.405360  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.168s	user 0.126s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":11482,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31842,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":93824,"update_count":2500}
I20260812 06:16:59.406026  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:16:59.469828  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.064s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26420,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.470327  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:59.480525  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.481029  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:59.659710  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.178s	user 0.101s	sys 0.065s 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":396,"lbm_read_time_us":11006,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31950,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:16:59.660298  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:16:59.719857  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.059s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23690,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.720449  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:59.732535  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.733156  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:16:59.922044  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.189s	user 0.113s	sys 0.065s 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":1110,"lbm_read_time_us":13394,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31472,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:16:59.922631  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:16:59.981235  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.058s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.981812  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:16:59.993333  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.993865  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:00.183108  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.189s	user 0.136s	sys 0.052s 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":836,"lbm_read_time_us":13161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34722,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:00.183846  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=11.118625
I20260812 06:17:00.228669  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.045s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18904,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:00.229288  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:00.259410  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.030s	user 0.003s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4565,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.259928  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:00.270974  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.271469  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:00.451812  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.180s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1140,"lbm_read_time_us":12478,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30535,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:00.452693  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=11.118625
I20260812 06:17:00.492036  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.039s	user 0.010s	sys 0.026s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16660,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:00.492718  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:00.514333  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.514890  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:00.573019  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.058s	user 0.039s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1508,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2226,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:00.574026  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5): 493 bytes on disk
I20260812 06:17:00.574595  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.575220  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=6.157687
I20260812 06:17:00.597738  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9207,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:00.598371  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling LogGCOp(e11c7d74749241de8ab93fb9e06c85b5): free 136275203 bytes of WAL
I20260812 06:17:00.598670  7126 log_reader.cc:385] T e11c7d74749241de8ab93fb9e06c85b5: removed 13 log segments from log reader
I20260812 06:17:00.598749  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000015 (ops 71-74)
I20260812 06:17:00.598798  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000016 (ops 75-79)
I20260812 06:17:00.598845  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000017 (ops 80-84)
I20260812 06:17:00.598889  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000018 (ops 85-89)
I20260812 06:17:00.598932  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000019 (ops 90-94)
I20260812 06:17:00.598968  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000020 (ops 95-99)
I20260812 06:17:00.599011  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000021 (ops 100-104)
I20260812 06:17:00.599052  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000022 (ops 105-109)
I20260812 06:17:00.599093  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000023 (ops 110-114)
I20260812 06:17:00.599138  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000024 (ops 115-119)
I20260812 06:17:00.599170  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000025 (ops 120-124)
I20260812 06:17:00.599200  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000026 (ops 125-129)
I20260812 06:17:00.599228  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000027 (ops 130-134)
I20260812 06:17:00.629525  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: LogGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:00.629992  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:00.641371  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.641950  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:00.874626  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.233s	user 0.146s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":7010,"lbm_read_time_us":14854,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37605,"lbm_writes_lt_1ms":743,"mutex_wait_us":3623,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:17:00.875180  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=18.063937
I20260812 06:17:00.947602  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.072s	user 0.054s	sys 0.008s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":29766,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:00.948084  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:00.958523  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.959106  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:01.155174  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.196s	user 0.127s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":13189,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34088,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44928,"update_count":3000}
I20260812 06:17:01.155862  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=15.087375
I20260812 06:17:01.202855  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20285,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:01.203676  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:01.228029  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5749,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.228533  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:01.240180  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.241067  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:01.443392  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.202s	user 0.145s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":178,"lbm_read_time_us":13544,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34757,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:01.444134  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:17:01.488945  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.045s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19696,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.489524  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:01.508492  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.509047  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:01.682279  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.173s	user 0.108s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1164,"lbm_read_time_us":12051,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29454,"lbm_writes_lt_1ms":543,"mutex_wait_us":397,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:01.682816  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:17:01.743024  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.060s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22002,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.743680  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:01.769766  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.026s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.770303  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:01.781280  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.781774  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:01.997787  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.216s	user 0.164s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":619,"lbm_read_time_us":14593,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39259,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:17:01.998533  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=14.095187
I20260812 06:17:02.049027  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.050s	user 0.029s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22404,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.049602  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:02.110692  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushMRSOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.061s	user 0.037s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":146,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2029,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:02.111465  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling LogGCOp(e11c7d74749241de8ab93fb9e06c85b5): free 112692556 bytes of WAL
I20260812 06:17:02.111716  7126 log_reader.cc:385] T e11c7d74749241de8ab93fb9e06c85b5: removed 11 log segments from log reader
I20260812 06:17:02.111763  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000028 (ops 135-139)
I20260812 06:17:02.111824  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000029 (ops 140-144)
I20260812 06:17:02.111873  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000030 (ops 145-149)
I20260812 06:17:02.111919  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000031 (ops 150-154)
I20260812 06:17:02.111960  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000032 (ops 155-159)
I20260812 06:17:02.112037  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000033 (ops 160-164)
I20260812 06:17:02.112080  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000034 (ops 165-169)
I20260812 06:17:02.112128  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000035 (ops 170-174)
I20260812 06:17:02.112171  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000036 (ops 175-179)
I20260812 06:17:02.112215  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000037 (ops 180-184)
I20260812 06:17:02.112259  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000038 (ops 185-189)
I20260812 06:17:02.138556  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: LogGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:02.139092  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5): 472 bytes on disk
I20260812 06:17:02.139683  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: UndoDeltaBlockGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4}
I20260812 06:17:02.140424  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=6.157687
I20260812 06:17:02.171836  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.031s	user 0.013s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13701,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:02.172400  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling LogGCOp(e11c7d74749241de8ab93fb9e06c85b5): free 8767197 bytes of WAL
I20260812 06:17:02.172639  7126 log_reader.cc:385] T e11c7d74749241de8ab93fb9e06c85b5: removed 1 log segments from log reader
I20260812 06:17:02.172688  7126 log.cc:1079] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/e11c7d74749241de8ab93fb9e06c85b5/wal-000000039 (ops 190-194)
I20260812 06:17:02.174623  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: LogGCOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:02.174959  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=2.188937
I20260812 06:17:02.188521  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: FlushDeltaMemStoresOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.189064  7235 maintenance_manager.cc:419] P c6acfbbd280a4ac79c03fdff47619121: Scheduling MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5): perf score=1.000000
I20260812 06:17:02.266598  6965 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.078s	user 1.887s	sys 0.173s
I20260812 06:17:02.360365  6965 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.002s	sys 0.000s
I20260812 06:17:02.361192  6965 tablet_server.cc:179] TabletServer@127.6.205.65:0 shutting down...
I20260812 06:17:02.408537  7126 maintenance_manager.cc:643] P c6acfbbd280a4ac79c03fdff47619121: MajorDeltaCompactionOp(e11c7d74749241de8ab93fb9e06c85b5) complete. Timing: real 0.219s	user 0.150s	sys 0.069s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1020,"lbm_read_time_us":17050,"lbm_reads_lt_1ms":769,"lbm_write_time_us":35763,"lbm_writes_lt_1ms":743,"mutex_wait_us":79,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20480,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:17:02.409327  6965 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:02.409906  6965 tablet_replica.cc:333] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121: stopping tablet replica
I20260812 06:17:02.410177  6965 raft_consensus.cc:2243] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.410432  6965 raft_consensus.cc:2272] T e11c7d74749241de8ab93fb9e06c85b5 P c6acfbbd280a4ac79c03fdff47619121 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.427798  6965 tablet_server.cc:196] TabletServer@127.6.205.65:0 shutdown complete.
I20260812 06:17:02.471439  6965 master.cc:562] Master@127.6.205.126:42715 shutting down...
I20260812 06:17:02.475697  6965 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.475915  6965 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.476013  6965 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8aa2ecd9468e4f25af6278ba142f3e9f: stopping tablet replica
I20260812 06:17:02.488605  6965 master.cc:584] Master@127.6.205.126:42715 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5678 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:02.575266  6965 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.205.126:38567
I20260812 06:17:02.575688  6965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.578215  7288 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:17:02.578277  6965 server_base.cc:1061] running on GCE node
W20260812 06:17:02.578316  7297 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:17:02.578332  7289 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:17:02.578720  6965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.578764  6965 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:17:02.578780  6965 hybrid_clock.cc:648] HybridClock initialized: now 1786515422578780 us; error 0 us; skew 500 ppm
I20260812 06:17:02.579612  6965 webserver.cc:533] Webserver started at http://127.6.205.126:39825/ using document root <none> and password file <none>
I20260812 06:17:02.579790  6965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.579838  6965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.579948  6965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.580391  6965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/master-0-root/instance:
uuid: "4b82d1c41dc84e0cb372551864db333c"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-3h5h"
I20260812 06:17:02.582094  6965 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:02.583132  7308 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:17:02.583416  6965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:02.583483  6965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/master-0-root
uuid: "4b82d1c41dc84e0cb372551864db333c"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-3h5h"
I20260812 06:17:02.583575  6965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-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:17:02.598567  6965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.599004  6965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.603374  6965 rpc_server.cc:307] RPC server started. Bound to: 127.6.205.126:38567
I20260812 06:17:02.606042  7392 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.205.126:38567 every 8 connection(s)
I20260812 06:17:02.607905  7395 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:17:02.616297  7395 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c: Bootstrap starting.
I20260812 06:17:02.617180  7395 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.618352  7395 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c: No bootstrap required, opened a new log
I20260812 06:17:02.618713  7395 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER }
I20260812 06:17:02.618798  7395 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.618819  7395 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4b82d1c41dc84e0cb372551864db333c, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.618923  7395 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [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: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER }
I20260812 06:17:02.618979  7395 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.619002  7395 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.619048  7395 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.619746  7395 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER }
I20260812 06:17:02.619863  7395 leader_election.cc:304] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [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: 4b82d1c41dc84e0cb372551864db333c; no voters: 
I20260812 06:17:02.620082  7395 leader_election.cc:290] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.620179  7400 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.620349  7400 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 1 LEADER]: Becoming Leader. State: Replica: 4b82d1c41dc84e0cb372551864db333c, State: Running, Role: LEADER
I20260812 06:17:02.620575  7395 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:02.620537  7400 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [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: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER }
I20260812 06:17:02.621030  7401 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4b82d1c41dc84e0cb372551864db333c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER } }
I20260812 06:17:02.621090  7403 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4b82d1c41dc84e0cb372551864db333c. Latest consensus state: current_term: 1 leader_uuid: "4b82d1c41dc84e0cb372551864db333c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b82d1c41dc84e0cb372551864db333c" member_type: VOTER } }
I20260812 06:17:02.621188  7401 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.621263  7403 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.621726  7407 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:02.622490  7407 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:02.622673  6965 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:02.624317  7407 catalog_manager.cc:1383] Generated new cluster ID: 6687494b4edb4ccfa901a7b4bad6bb8e
I20260812 06:17:02.624378  7407 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:02.642889  7407 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:02.643492  7407 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:02.648563  7407 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c: Generated new TSK 0
I20260812 06:17:02.648785  7407 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:02.655179  6965 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:02.657310  6965 server_base.cc:1061] running on GCE node
W20260812 06:17:02.657361  7435 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:17:02.657429  7432 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:17:02.657449  7431 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:17:02.657686  6965 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.657738  6965 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:17:02.657755  6965 hybrid_clock.cc:648] HybridClock initialized: now 1786515422657755 us; error 0 us; skew 500 ppm
I20260812 06:17:02.658807  6965 webserver.cc:533] Webserver started at http://127.6.205.65:44817/ using document root <none> and password file <none>
I20260812 06:17:02.658957  6965 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.659004  6965 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.659066  6965 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.659439  6965 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/instance:
uuid: "b85ac521982d420b8cdad3eb30ef279c"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-3h5h"
I20260812 06:17:02.661105  6965 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:02.662191  7443 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:17:02.662464  6965 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:02.662551  6965 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root
uuid: "b85ac521982d420b8cdad3eb30ef279c"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-3h5h"
I20260812 06:17:02.662626  6965 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-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:17:02.682300  6965 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.682724  6965 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.683051  6965 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:02.683538  6965 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:02.683602  6965 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.683667  6965 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:02.683703  6965 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.688442  6965 rpc_server.cc:307] RPC server started. Bound to: 127.6.205.65:45429
I20260812 06:17:02.689144  7556 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.205.65:45429 every 8 connection(s)
I20260812 06:17:02.697486  7557 heartbeater.cc:344] Connected to a master server at 127.6.205.126:38567
I20260812 06:17:02.697620  7557 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:02.697886  7557 heartbeater.cc:507] Master 127.6.205.126:38567 requested a full tablet report, sending...
I20260812 06:17:02.698617  7336 ts_manager.cc:194] Registered new tserver with Master: b85ac521982d420b8cdad3eb30ef279c (127.6.205.65:45429)
I20260812 06:17:02.699283  6965 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010056115s
I20260812 06:17:02.699514  7336 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36986
I20260812 06:17:02.706867  7336 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36994:
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:17:02.716039  7495 tablet_service.cc:1511] Processing CreateTablet for tablet 37a9835b95be4f6f8c8cbb83b86d0bd7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7a971132462549679765fa40e3894946]), partition=
I20260812 06:17:02.716336  7495 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 37a9835b95be4f6f8c8cbb83b86d0bd7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.718777  7577 tablet_bootstrap.cc:492] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Bootstrap starting.
I20260812 06:17:02.719569  7577 tablet_bootstrap.cc:654] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.720629  7577 tablet_bootstrap.cc:492] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: No bootstrap required, opened a new log
I20260812 06:17:02.720773  7577 ts_tablet_manager.cc:1403] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:02.721225  7577 raft_consensus.cc:359] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b85ac521982d420b8cdad3eb30ef279c" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 45429 } }
I20260812 06:17:02.721341  7577 raft_consensus.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.721411  7577 raft_consensus.cc:740] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b85ac521982d420b8cdad3eb30ef279c, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.721632  7577 consensus_queue.cc:260] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [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: "b85ac521982d420b8cdad3eb30ef279c" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 45429 } }
I20260812 06:17:02.721771  7577 raft_consensus.cc:399] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.721817  7577 raft_consensus.cc:493] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.721868  7577 raft_consensus.cc:3060] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.722631  7577 raft_consensus.cc:515] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b85ac521982d420b8cdad3eb30ef279c" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 45429 } }
I20260812 06:17:02.722841  7577 leader_election.cc:304] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [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: b85ac521982d420b8cdad3eb30ef279c; no voters: 
I20260812 06:17:02.723069  7577 leader_election.cc:290] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.723254  7579 raft_consensus.cc:2804] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.723419  7577 ts_tablet_manager.cc:1434] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:02.723460  7557 heartbeater.cc:499] Master 127.6.205.126:38567 was elected leader, sending a full tablet report...
I20260812 06:17:02.723501  7579 raft_consensus.cc:697] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 1 LEADER]: Becoming Leader. State: Replica: b85ac521982d420b8cdad3eb30ef279c, State: Running, Role: LEADER
I20260812 06:17:02.723631  7579 consensus_queue.cc:237] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [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: "b85ac521982d420b8cdad3eb30ef279c" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 45429 } }
I20260812 06:17:02.725291  7336 catalog_manager.cc:5719] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c reported cstate change: term changed from 0 to 1, leader changed from <none> to b85ac521982d420b8cdad3eb30ef279c (127.6.205.65). New cstate: current_term: 1 leader_uuid: "b85ac521982d420b8cdad3eb30ef279c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b85ac521982d420b8cdad3eb30ef279c" member_type: VOTER last_known_addr { host: "127.6.205.65" port: 45429 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:02.788601  6965 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.016s	sys 0.008s
I20260812 06:17:02.939926  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=19.054940
I20260812 06:17:03.100878  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.161s	user 0.124s	sys 0.036s Metrics: {"bytes_written":12676710,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1127,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39013,"lbm_writes_lt_1ms":766,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":7424,"update_count":1545}
I20260812 06:17:03.101723  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): free 20743880 bytes of WAL
I20260812 06:17:03.102020  7451 log_reader.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7: removed 2 log segments from log reader
I20260812 06:17:03.102087  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000001 (ops 1-6)
I20260812 06:17:03.102133  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000002 (ops 7-11)
I20260812 06:17:03.107152  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:03.107722  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:03.125219  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4143687,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:03.125674  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): 16411394 bytes on disk
I20260812 06:17:03.126080  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.126480  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:03.136325  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3624,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.136771  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:03.320040  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.183s	user 0.098s	sys 0.073s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":670,"lbm_read_time_us":13311,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31399,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":313,"threads_started":5,"update_count":2500}
I20260812 06:17:03.320549  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:03.371958  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.051s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.372488  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:03.388190  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.388739  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:03.552649  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.164s	user 0.128s	sys 0.025s 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":293,"lbm_read_time_us":9958,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30019,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70784,"update_count":2500}
I20260812 06:17:03.556165  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:03.607414  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.051s	user 0.040s	sys 0.006s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21601,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.607887  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:03.619688  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.620282  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:03.805581  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.185s	user 0.137s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":569,"lbm_read_time_us":10337,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32848,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:17:03.806241  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:03.854939  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.048s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21097,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.855489  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:04.020586  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.165s	user 0.109s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":303,"lbm_read_time_us":12687,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26856,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:04.021335  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:04.071655  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.050s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21733,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.072264  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:04.086254  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.086788  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:04.277967  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.191s	user 0.122s	sys 0.058s 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":947,"lbm_read_time_us":13047,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29185,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:17:04.278699  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:04.338503  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.060s	user 0.045s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24325,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.338967  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:04.351186  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.351791  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:04.381795  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.030s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1442,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:04.382463  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): free 112692366 bytes of WAL
I20260812 06:17:04.382730  7451 log_reader.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7: removed 11 log segments from log reader
I20260812 06:17:04.382791  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000003 (ops 12-16)
I20260812 06:17:04.382830  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000004 (ops 17-21)
I20260812 06:17:04.382858  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000005 (ops 22-26)
I20260812 06:17:04.382879  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000006 (ops 27-31)
I20260812 06:17:04.382912  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000007 (ops 32-36)
I20260812 06:17:04.382942  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000008 (ops 37-41)
I20260812 06:17:04.382964  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000009 (ops 42-46)
I20260812 06:17:04.382993  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000010 (ops 47-51)
I20260812 06:17:04.383021  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000011 (ops 52-56)
I20260812 06:17:04.383047  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000012 (ops 57-61)
I20260812 06:17:04.383075  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000013 (ops 62-66)
I20260812 06:17:04.411535  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:04.412026  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): 463 bytes on disk
I20260812 06:17:04.412659  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:04.413254  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:04.447626  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.034s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.448148  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:04.463091  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.463719  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:04.719108  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.255s	user 0.165s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":537,"lbm_read_time_us":18189,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41018,"lbm_writes_lt_1ms":743,"mutex_wait_us":66,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:17:04.719969  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=18.063937
I20260812 06:17:04.789340  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.069s	user 0.043s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32323,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:04.789850  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=3.181125
I20260812 06:17:04.806670  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.017s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:04.807174  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:04.820757  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5192,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:04.821293  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:05.046434  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.225s	user 0.115s	sys 0.103s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1100,"lbm_read_time_us":14997,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40620,"lbm_writes_lt_1ms":743,"mutex_wait_us":308,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":3500}
I20260812 06:17:05.047025  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=18.063937
I20260812 06:17:05.101230  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.054s	user 0.045s	sys 0.008s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24057,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.101743  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:05.118980  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.119495  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:05.284586  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.165s	user 0.125s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":11192,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34898,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":3000}
I20260812 06:17:05.285215  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:05.342857  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.057s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.343473  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:05.355206  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.355710  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:05.523887  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.168s	user 0.137s	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":1466,"lbm_read_time_us":10803,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31021,"lbm_writes_lt_1ms":543,"mutex_wait_us":474,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:05.524645  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:05.574342  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.049s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21453,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.574842  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:05.722298  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.147s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":579,"lbm_read_time_us":9545,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24051,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.722976  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:05.772430  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.049s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21367,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.773052  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:05.785444  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.786761  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:05.825551  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.039s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1389,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1694,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:05.826233  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): free 124257241 bytes of WAL
I20260812 06:17:05.826468  7451 log_reader.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7: removed 12 log segments from log reader
I20260812 06:17:05.826511  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000014 (ops 67-71)
I20260812 06:17:05.826540  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000015 (ops 72-76)
I20260812 06:17:05.826599  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000016 (ops 77-81)
I20260812 06:17:05.826630  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000017 (ops 82-86)
I20260812 06:17:05.826683  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000018 (ops 87-90)
I20260812 06:17:05.826741  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000019 (ops 91-95)
I20260812 06:17:05.826779  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000020 (ops 96-100)
I20260812 06:17:05.826817  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000021 (ops 101-105)
I20260812 06:17:05.826855  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000022 (ops 106-110)
I20260812 06:17:05.826896  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000023 (ops 111-115)
I20260812 06:17:05.826934  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000024 (ops 116-120)
I20260812 06:17:05.826972  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000025 (ops 121-125)
I20260812 06:17:05.854521  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:05.855125  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): 462 bytes on disk
I20260812 06:17:05.855726  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.856472  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=3.181125
I20260812 06:17:05.877868  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.021s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:05.878422  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:05.890206  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:05.890686  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:06.138932  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.248s	user 0.164s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":518,"lbm_read_time_us":17362,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42324,"lbm_writes_lt_1ms":743,"mutex_wait_us":57,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24576,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:17:06.139928  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=18.063937
I20260812 06:17:06.198027  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.058s	user 0.034s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26149,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:06.198596  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:06.214954  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.215489  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:06.420579  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.205s	user 0.132s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":12754,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32455,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":3000}
I20260812 06:17:06.421491  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=18.063937
I20260812 06:17:06.497169  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.075s	user 0.048s	sys 0.020s Metrics: {"bytes_written":20512322,"delete_count":0,"lbm_write_time_us":30448,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:06.497792  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:06.512307  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.513019  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:06.744289  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.231s	user 0.150s	sys 0.073s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":424,"lbm_read_time_us":14095,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37459,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":3000}
I20260812 06:17:06.745018  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=18.063937
I20260812 06:17:06.819424  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.074s	user 0.046s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27557,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:06.819959  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:06.831349  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.831930  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:07.046312  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.214s	user 0.132s	sys 0.082s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":14519,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37405,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":31232,"update_count":3000}
I20260812 06:17:07.049435  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=15.087375
I20260812 06:17:07.097436  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.048s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20762,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:07.098027  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:07.124359  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.026s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4964,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.124925  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:07.136583  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.137109  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:07.343887  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.207s	user 0.137s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":624,"lbm_read_time_us":13285,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33750,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:17:07.344671  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=15.087375
I20260812 06:17:07.390403  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":20588,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:07.391114  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:07.414091  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.023s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5985,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.414574  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:07.468115  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushMRSOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.053s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1672,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2380,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:07.468797  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): free 129320767 bytes of WAL
I20260812 06:17:07.469103  7451 log_reader.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7: removed 13 log segments from log reader
I20260812 06:17:07.469151  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000026 (ops 126-130)
I20260812 06:17:07.469182  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000027 (ops 131-135)
I20260812 06:17:07.469249  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000028 (ops 136-140)
I20260812 06:17:07.469292  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000029 (ops 141-144)
I20260812 06:17:07.469334  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000030 (ops 145-149)
I20260812 06:17:07.469379  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000031 (ops 150-154)
I20260812 06:17:07.469422  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000032 (ops 155-158)
I20260812 06:17:07.469463  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000033 (ops 159-163)
I20260812 06:17:07.469504  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000034 (ops 164-168)
I20260812 06:17:07.469544  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000035 (ops 169-173)
I20260812 06:17:07.469599  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000036 (ops 174-178)
I20260812 06:17:07.469635  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000037 (ops 179-183)
I20260812 06:17:07.469681  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000038 (ops 184-188)
I20260812 06:17:07.499627  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:07.500167  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): 492 bytes on disk
I20260812 06:17:07.500797  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: UndoDeltaBlockGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.501562  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=7.149875
I20260812 06:17:07.532389  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.031s	user 0.021s	sys 0.007s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":13267,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:07.532966  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7): free 11564893 bytes of WAL
I20260812 06:17:07.533203  7451 log_reader.cc:385] T 37a9835b95be4f6f8c8cbb83b86d0bd7: removed 1 log segments from log reader
I20260812 06:17:07.533249  7451 log.cc:1079] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: Deleting log segment in path: /tmp/dist-test-taskh9EEbu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416885795-6965-0/minicluster-data/ts-0-root/wals/37a9835b95be4f6f8c8cbb83b86d0bd7/wal-000000039 (ops 189-192)
I20260812 06:17:07.535827  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: LogGCOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:07.536367  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=2.188937
I20260812 06:17:07.551681  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5553,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.552204  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=1.000000
I20260812 06:17:07.715411  6965 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.927s	user 1.837s	sys 0.146s
I20260812 06:17:07.796171  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: MajorDeltaCompactionOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.244s	user 0.195s	sys 0.047s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082142,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15528,"lbm_reads_lt_1ms":862,"lbm_write_time_us":48104,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":4000}
I20260812 06:17:07.796664  7559 maintenance_manager.cc:419] P b85ac521982d420b8cdad3eb30ef279c: Scheduling FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7): perf score=14.095187
I20260812 06:17:07.824232  6965 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.002s	sys 0.000s
I20260812 06:17:07.824919  6965 tablet_server.cc:179] TabletServer@127.6.205.65:0 shutting down...
I20260812 06:17:07.873941  7451 maintenance_manager.cc:643] P b85ac521982d420b8cdad3eb30ef279c: FlushDeltaMemStoresOp(37a9835b95be4f6f8c8cbb83b86d0bd7) complete. Timing: real 0.077s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20931,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.874564  6965 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:07.874776  6965 tablet_replica.cc:333] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c: stopping tablet replica
I20260812 06:17:07.874902  6965 raft_consensus.cc:2243] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.875092  6965 raft_consensus.cc:2272] T 37a9835b95be4f6f8c8cbb83b86d0bd7 P b85ac521982d420b8cdad3eb30ef279c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.878998  6965 tablet_server.cc:196] TabletServer@127.6.205.65:0 shutdown complete.
I20260812 06:17:07.884783  6965 master.cc:562] Master@127.6.205.126:38567 shutting down...
I20260812 06:17:07.888607  6965 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.888777  6965 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.888909  6965 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4b82d1c41dc84e0cb372551864db333c: stopping tablet replica
I20260812 06:17:07.891532  6965 master.cc:584] Master@127.6.205.126:38567 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5415 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11095 ms total)

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