[==========] 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:20:00.597107  3078 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.1.190:42903
I20260812 06:20:00.598299  3078 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:20:00.598955  3078 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.606154  3084 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:20:00.606323  3078 server_base.cc:1061] running on GCE node
W20260812 06:20:00.606381  3086 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:20:00.606652  3083 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:20:00.607163  3078 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.607306  3078 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:20:00.607376  3078 hybrid_clock.cc:648] HybridClock initialized: now 1786515600607372 us; error 0 us; skew 500 ppm
I20260812 06:20:00.609480  3078 webserver.cc:533] Webserver started at http://127.3.1.190:45097/ using document root <none> and password file <none>
I20260812 06:20:00.610137  3078 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.610237  3078 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.610510  3078 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.612275  3078 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/master-0-root/instance:
uuid: "fd1c00a30a1c43fa89c217a5f209c72e"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-9zdj"
I20260812 06:20:00.616127  3078 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:00.618620  3091 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:20:00.620009  3078 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:00.620163  3078 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/master-0-root
uuid: "fd1c00a30a1c43fa89c217a5f209c72e"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-9zdj"
I20260812 06:20:00.620292  3078 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-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:20:00.635610  3078 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.636384  3078 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:20:00.636603  3078 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.645227  3155 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.1.190:42903 every 8 connection(s)
I20260812 06:20:00.645255  3078 rpc_server.cc:307] RPC server started. Bound to: 127.3.1.190:42903
I20260812 06:20:00.648161  3156 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:20:00.654711  3156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: Bootstrap starting.
I20260812 06:20:00.657392  3156 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.658936  3156 log.cc:826] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:00.661461  3156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: No bootstrap required, opened a new log
I20260812 06:20:00.664754  3156 raft_consensus.cc:359] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER }
I20260812 06:20:00.664988  3156 raft_consensus.cc:385] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.665048  3156 raft_consensus.cc:740] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fd1c00a30a1c43fa89c217a5f209c72e, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.665904  3156 consensus_queue.cc:260] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [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: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER }
I20260812 06:20:00.666079  3156 raft_consensus.cc:399] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.666132  3156 raft_consensus.cc:493] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.666230  3156 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.667088  3156 raft_consensus.cc:515] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER }
I20260812 06:20:00.667557  3156 leader_election.cc:304] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [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: fd1c00a30a1c43fa89c217a5f209c72e; no voters: 
I20260812 06:20:00.667887  3156 leader_election.cc:290] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.668247  3159 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.668551  3159 raft_consensus.cc:697] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 1 LEADER]: Becoming Leader. State: Replica: fd1c00a30a1c43fa89c217a5f209c72e, State: Running, Role: LEADER
I20260812 06:20:00.668977  3159 consensus_queue.cc:237] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [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: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER }
I20260812 06:20:00.669103  3156 sys_catalog.cc:565] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.671375  3160 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER } }
I20260812 06:20:00.671375  3161 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [sys.catalog]: SysCatalogTable state changed. Reason: New leader fd1c00a30a1c43fa89c217a5f209c72e. Latest consensus state: current_term: 1 leader_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd1c00a30a1c43fa89c217a5f209c72e" member_type: VOTER } }
I20260812 06:20:00.671545  3161 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.671663  3078 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.671545  3160 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [sys.catalog]: This master's current role is: LEADER
W20260812 06:20:00.674043  3174 catalog_manager.cc:1594] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:00.674120  3174 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:00.674180  3175 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.674988  3175 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.680135  3175 catalog_manager.cc:1383] Generated new cluster ID: 8cbc4ac9058541f1812957b8315c5bd0
I20260812 06:20:00.680284  3175 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.689961  3175 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.691008  3175 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.697818  3175 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: Generated new TSK 0
I20260812 06:20:00.698647  3175 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.704485  3078 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.707758  3182 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:20:00.707834  3181 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:20:00.707924  3078 server_base.cc:1061] running on GCE node
W20260812 06:20:00.707800  3186 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:20:00.708294  3078 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.708372  3078 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:20:00.708403  3078 hybrid_clock.cc:648] HybridClock initialized: now 1786515600708402 us; error 0 us; skew 500 ppm
I20260812 06:20:00.709548  3078 webserver.cc:533] Webserver started at http://127.3.1.129:45147/ using document root <none> and password file <none>
I20260812 06:20:00.709800  3078 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.709880  3078 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.709973  3078 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.710484  3078 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/instance:
uuid: "8f5ad921a26647d79330ccb5c80bd0c5"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-9zdj"
I20260812 06:20:00.712363  3078 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:00.713586  3191 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:20:00.713958  3078 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:20:00.714038  3078 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root
uuid: "8f5ad921a26647d79330ccb5c80bd0c5"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-9zdj"
I20260812 06:20:00.714140  3078 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-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:20:00.731585  3078 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.732142  3078 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.732800  3078 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.733801  3078 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.733880  3078 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.733960  3078 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.734004  3078 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.741077  3078 rpc_server.cc:307] RPC server started. Bound to: 127.3.1.129:40865
I20260812 06:20:00.741142  3263 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.1.129:40865 every 8 connection(s)
I20260812 06:20:00.753153  3264 heartbeater.cc:344] Connected to a master server at 127.3.1.190:42903
I20260812 06:20:00.753518  3264 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.754050  3264 heartbeater.cc:507] Master 127.3.1.190:42903 requested a full tablet report, sending...
I20260812 06:20:00.755892  3117 ts_manager.cc:194] Registered new tserver with Master: 8f5ad921a26647d79330ccb5c80bd0c5 (127.3.1.129:40865)
I20260812 06:20:00.756609  3078 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014767213s
I20260812 06:20:00.757462  3117 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32950
I20260812 06:20:00.768587  3117 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32964:
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:20:00.784869  3223 tablet_service.cc:1511] Processing CreateTablet for tablet 378c64113c2b418a9577e924177ef8d7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ac2331cc1567422c885b66caa09e2317]), partition=
I20260812 06:20:00.785620  3223 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 378c64113c2b418a9577e924177ef8d7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.787985  3277 tablet_bootstrap.cc:492] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Bootstrap starting.
I20260812 06:20:00.789310  3277 tablet_bootstrap.cc:654] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.790665  3277 tablet_bootstrap.cc:492] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: No bootstrap required, opened a new log
I20260812 06:20:00.790789  3277 ts_tablet_manager.cc:1403] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:00.791246  3277 raft_consensus.cc:359] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f5ad921a26647d79330ccb5c80bd0c5" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 40865 } }
I20260812 06:20:00.791354  3277 raft_consensus.cc:385] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.791402  3277 raft_consensus.cc:740] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8f5ad921a26647d79330ccb5c80bd0c5, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.791592  3277 consensus_queue.cc:260] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [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: "8f5ad921a26647d79330ccb5c80bd0c5" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 40865 } }
I20260812 06:20:00.791688  3277 raft_consensus.cc:399] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.791751  3277 raft_consensus.cc:493] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.791828  3277 raft_consensus.cc:3060] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.793183  3277 raft_consensus.cc:515] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f5ad921a26647d79330ccb5c80bd0c5" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 40865 } }
I20260812 06:20:00.793380  3277 leader_election.cc:304] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [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: 8f5ad921a26647d79330ccb5c80bd0c5; no voters: 
I20260812 06:20:00.793679  3277 leader_election.cc:290] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.793766  3279 raft_consensus.cc:2804] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.793963  3279 raft_consensus.cc:697] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 1 LEADER]: Becoming Leader. State: Replica: 8f5ad921a26647d79330ccb5c80bd0c5, State: Running, Role: LEADER
I20260812 06:20:00.794107  3277 ts_tablet_manager.cc:1434] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:20:00.794312  3264 heartbeater.cc:499] Master 127.3.1.190:42903 was elected leader, sending a full tablet report...
I20260812 06:20:00.794642  3279 consensus_queue.cc:237] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [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: "8f5ad921a26647d79330ccb5c80bd0c5" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 40865 } }
I20260812 06:20:00.797837  3117 catalog_manager.cc:5719] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8f5ad921a26647d79330ccb5c80bd0c5 (127.3.1.129). New cstate: current_term: 1 leader_uuid: "8f5ad921a26647d79330ccb5c80bd0c5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f5ad921a26647d79330ccb5c80bd0c5" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 40865 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.887728  3078 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.080s	user 0.019s	sys 0.012s
I20260812 06:20:00.992372  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushMRSOp(378c64113c2b418a9577e924177ef8d7): perf score=11.117440
I20260812 06:20:01.139132  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushMRSOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.146s	user 0.119s	sys 0.019s Metrics: {"bytes_written":8984539,"cfile_init":1,"compiler_manager_pool.queue_time_us":202,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":843,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33447,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":485,"mutex_wait_us":234,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":2304,"thread_start_us":129,"threads_started":1,"update_count":1095}
I20260812 06:20:01.140522  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling LogGCOp(378c64113c2b418a9577e924177ef8d7): free 8725963 bytes of WAL
I20260812 06:20:01.140928  3196 log_reader.cc:385] T 378c64113c2b418a9577e924177ef8d7: removed 1 log segments from log reader
I20260812 06:20:01.141048  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000001 (ops 1-6)
I20260812 06:20:01.143791  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: LogGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:01.144184  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=1.196750
I20260812 06:20:01.157989  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":4315,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:20:01.158641  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:01.298175  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.139s	user 0.116s	sys 0.012s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16118632,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":7894,"lbm_reads_lt_1ms":354,"lbm_write_time_us":21996,"lbm_writes_lt_1ms":333,"mutex_wait_us":29,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":328,"threads_started":5,"update_count":1450}
I20260812 06:20:01.298787  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7): 8616791 bytes on disk
I20260812 06:20:01.299333  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.299913  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:01.361152  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.059s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19507,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.361801  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:01.375396  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.376071  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:01.525269  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.149s	user 0.113s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":10764,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28391,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:20:01.526053  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:01.571491  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.045s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":18890,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.572113  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:01.593070  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.021s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.593717  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:01.741317  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.147s	user 0.102s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631317,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1026,"lbm_read_time_us":9786,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25349,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:20:01.742127  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:01.784617  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.042s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15685,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.785207  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:01.799609  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.800302  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:01.942796  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.142s	user 0.138s	sys 0.004s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":9943,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28552,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:20:01.943650  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:01.987987  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.044s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19291,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.988619  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.008351  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.008976  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:02.145705  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.137s	user 0.120s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1254,"lbm_read_time_us":9465,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27248,"lbm_writes_lt_1ms":443,"mutex_wait_us":365,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:02.146508  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:02.191913  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.045s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15686,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:20:02.192696  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.204456  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.205227  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:02.354147  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.149s	user 0.122s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":11708,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24501,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.354940  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:02.393157  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16844,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.393704  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.405395  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.406060  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:02.533674  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.127s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":8706,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24833,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:02.534405  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:02.580441  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.046s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.580977  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.593346  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.594091  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushMRSOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:02.627315  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushMRSOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":312,"dirs.run_wall_time_us":1618,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1880,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:02.628315  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling LogGCOp(378c64113c2b418a9577e924177ef8d7): free 127961112 bytes of WAL
I20260812 06:20:02.628630  3196 log_reader.cc:385] T 378c64113c2b418a9577e924177ef8d7: removed 12 log segments from log reader
I20260812 06:20:02.628693  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000002 (ops 7-11)
I20260812 06:20:02.628736  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000003 (ops 12-16)
I20260812 06:20:02.628769  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000004 (ops 17-21)
I20260812 06:20:02.628798  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000005 (ops 22-26)
I20260812 06:20:02.628819  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000006 (ops 27-31)
I20260812 06:20:02.628850  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000007 (ops 32-36)
I20260812 06:20:02.628877  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000008 (ops 37-41)
I20260812 06:20:02.628911  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000009 (ops 42-46)
I20260812 06:20:02.628942  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000010 (ops 47-51)
I20260812 06:20:02.628971  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000011 (ops 52-56)
I20260812 06:20:02.628999  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000012 (ops 57-61)
I20260812 06:20:02.629029  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000013 (ops 62-66)
I20260812 06:20:02.663386  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: LogGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.035s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:20:02.663967  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=3.181125
I20260812 06:20:02.685117  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.021s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":8156,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:02.685767  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7): 473 bytes on disk
I20260812 06:20:02.686225  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.686719  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.699626  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4495,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.700176  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:02.896281  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.196s	user 0.145s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":794,"lbm_read_time_us":11982,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39742,"lbm_writes_lt_1ms":643,"mutex_wait_us":402,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:20:02.897038  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:02.955010  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.058s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19632,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.955699  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:02.968456  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.968946  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:03.135109  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.166s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":9996,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34310,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:20:03.135985  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=10.126437
I20260812 06:20:03.177707  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.041s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17976,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.178434  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:03.197523  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.198084  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:03.352473  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.154s	user 0.101s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":813,"lbm_read_time_us":9809,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26362,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.353019  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=11.118625
I20260812 06:20:03.385243  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.032s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14150,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.385885  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:03.405579  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6996,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.406343  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:03.563897  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.157s	user 0.117s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":8809,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23669,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:20:03.564545  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=11.118625
I20260812 06:20:03.608116  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21055,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.608639  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:03.620811  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4084,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.621385  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:03.751935  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.130s	user 0.093s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1297,"lbm_read_time_us":7949,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25371,"lbm_writes_lt_1ms":443,"mutex_wait_us":335,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:20:03.752542  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=11.118625
I20260812 06:20:03.801363  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.049s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19281,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.802085  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:03.820485  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.018s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.821004  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:03.831506  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3786,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.832123  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:04.008725  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.176s	user 0.137s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1192,"lbm_read_time_us":11161,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34471,"lbm_writes_lt_1ms":543,"mutex_wait_us":621,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:04.010468  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=12.110812
I20260812 06:20:04.058763  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.048s	user 0.013s	sys 0.032s Metrics: {"bytes_written":13538209,"delete_count":0,"lbm_write_time_us":21980,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":330,"reinsert_count":0,"update_count":1650}
I20260812 06:20:04.059340  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.079701  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.020s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":3497,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:20:04.080308  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.094487  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.014s	user 0.002s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5254,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.095213  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushMRSOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:04.132012  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushMRSOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.037s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1587,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1358,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:04.132891  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling LogGCOp(378c64113c2b418a9577e924177ef8d7): free 120553382 bytes of WAL
I20260812 06:20:04.133224  3196 log_reader.cc:385] T 378c64113c2b418a9577e924177ef8d7: removed 12 log segments from log reader
I20260812 06:20:04.133291  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000014 (ops 67-71)
I20260812 06:20:04.133334  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000015 (ops 72-76)
I20260812 06:20:04.133374  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000016 (ops 77-81)
I20260812 06:20:04.133409  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000017 (ops 82-86)
I20260812 06:20:04.133433  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000018 (ops 87-90)
I20260812 06:20:04.133455  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000019 (ops 91-95)
I20260812 06:20:04.133486  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000020 (ops 96-100)
I20260812 06:20:04.133512  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000021 (ops 101-105)
I20260812 06:20:04.133546  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000022 (ops 106-110)
I20260812 06:20:04.133579  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000023 (ops 111-115)
I20260812 06:20:04.133641  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000024 (ops 116-120)
I20260812 06:20:04.133687  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000025 (ops 121-124)
I20260812 06:20:04.166353  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: LogGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.033s	user 0.004s	sys 0.028s Metrics: {}
I20260812 06:20:04.167090  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7): 462 bytes on disk
I20260812 06:20:04.168038  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.168880  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.191107  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.191659  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.203670  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.204437  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:04.433037  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.228s	user 0.135s	sys 0.084s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":699,"lbm_read_time_us":17052,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39448,"lbm_writes_lt_1ms":743,"mutex_wait_us":584,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:04.433581  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=18.063937
I20260812 06:20:04.504524  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.071s	user 0.050s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31393,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:04.505084  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.517334  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.517917  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:04.694541  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.176s	user 0.128s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":423,"lbm_read_time_us":13907,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35053,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3000}
I20260812 06:20:04.698967  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:04.757908  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.059s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26642,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.758603  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:04.781199  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.022s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7527,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.782032  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:04.948913  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.167s	user 0.101s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1406,"lbm_read_time_us":10241,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32124,"lbm_writes_lt_1ms":543,"mutex_wait_us":361,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:04.949849  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:05.007452  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.057s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23834,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.008056  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:05.175798  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.168s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":217,"lbm_read_time_us":10714,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27033,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.176419  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:05.234541  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.058s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22291,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.235093  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:05.246879  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.247777  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:05.445405  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.197s	user 0.134s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":12356,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29031,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:20:05.446075  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:05.498382  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.052s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21076,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.499059  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:05.515859  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.017s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.516731  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:05.696902  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.180s	user 0.136s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1129,"lbm_read_time_us":13638,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34104,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:05.697937  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=11.118625
I20260812 06:20:05.737993  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.040s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16779,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.738636  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:05.761440  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.762092  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=2.188937
I20260812 06:20:05.772964  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3860,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.773526  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushMRSOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:05.804139  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushMRSOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.030s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":134,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1953,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1913,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:05.804966  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling LogGCOp(378c64113c2b418a9577e924177ef8d7): free 133024636 bytes of WAL
I20260812 06:20:05.805243  3196 log_reader.cc:385] T 378c64113c2b418a9577e924177ef8d7: removed 13 log segments from log reader
I20260812 06:20:05.805294  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000026 (ops 125-129)
I20260812 06:20:05.805325  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000027 (ops 130-134)
I20260812 06:20:05.805392  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000028 (ops 135-139)
I20260812 06:20:05.805439  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000029 (ops 140-144)
I20260812 06:20:05.805481  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000030 (ops 145-149)
I20260812 06:20:05.805540  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000031 (ops 150-154)
I20260812 06:20:05.805588  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000032 (ops 155-158)
I20260812 06:20:05.805660  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000033 (ops 159-163)
I20260812 06:20:05.805696  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000034 (ops 164-168)
I20260812 06:20:05.805742  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000035 (ops 169-173)
I20260812 06:20:05.805781  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000036 (ops 174-178)
I20260812 06:20:05.805823  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000037 (ops 179-183)
I20260812 06:20:05.805863  3196 log.cc:1079] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/378c64113c2b418a9577e924177ef8d7/wal-000000038 (ops 184-188)
I20260812 06:20:05.838080  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: LogGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:20:05.838665  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=4.173312
I20260812 06:20:05.864792  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":6008,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:20:05.865541  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=1.196750
I20260812 06:20:05.880015  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.014s	user 0.006s	sys 0.006s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":5049,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:05.880715  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:06.110219  3078 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.222s	user 1.908s	sys 0.140s
I20260812 06:20:06.125947  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.245s	user 0.136s	sys 0.108s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938872,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":18457,"lbm_reads_lt_1ms":771,"lbm_write_time_us":42169,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:20:06.126469  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7): 493 bytes on disk
I20260812 06:20:06.126955  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: UndoDeltaBlockGCOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.127518  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7): perf score=14.095187
I20260812 06:20:06.161979  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: FlushDeltaMemStoresOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.034s	user 0.029s	sys 0.005s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.162536  3266 maintenance_manager.cc:419] P 8f5ad921a26647d79330ccb5c80bd0c5: Scheduling MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7): perf score=1.000000
I20260812 06:20:06.220089  3078 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.109s	user 0.003s	sys 0.000s
I20260812 06:20:06.220865  3078 tablet_server.cc:179] TabletServer@127.3.1.129:0 shutting down...
I20260812 06:20:06.310456  3196 maintenance_manager.cc:643] P 8f5ad921a26647d79330ccb5c80bd0c5: MajorDeltaCompactionOp(378c64113c2b418a9577e924177ef8d7) complete. Timing: real 0.148s	user 0.090s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":520,"lbm_read_time_us":8750,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26270,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":2000}
I20260812 06:20:06.311780  3078 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:06.312354  3078 tablet_replica.cc:333] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5: stopping tablet replica
I20260812 06:20:06.312659  3078 raft_consensus.cc:2243] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.312930  3078 raft_consensus.cc:2272] T 378c64113c2b418a9577e924177ef8d7 P 8f5ad921a26647d79330ccb5c80bd0c5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.329517  3078 tablet_server.cc:196] TabletServer@127.3.1.129:0 shutdown complete.
I20260812 06:20:06.350644  3078 master.cc:562] Master@127.3.1.190:42903 shutting down...
I20260812 06:20:06.354858  3078 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.355093  3078 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.355187  3078 tablet_replica.cc:333] T 00000000000000000000000000000000 P fd1c00a30a1c43fa89c217a5f209c72e: stopping tablet replica
I20260812 06:20:06.368124  3078 master.cc:584] Master@127.3.1.190:42903 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5867 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:06.464529  3078 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.1.190:41421
I20260812 06:20:06.464974  3078 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:06.467658  3078 server_base.cc:1061] running on GCE node
W20260812 06:20:06.467669  3306 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:20:06.467705  3303 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.467723  3304 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:20:06.468117  3078 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.468163  3078 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:20:06.468178  3078 hybrid_clock.cc:648] HybridClock initialized: now 1786515606468178 us; error 0 us; skew 500 ppm
I20260812 06:20:06.469105  3078 webserver.cc:533] Webserver started at http://127.3.1.190:44193/ using document root <none> and password file <none>
I20260812 06:20:06.469293  3078 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.469344  3078 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.469455  3078 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.469957  3078 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/master-0-root/instance:
uuid: "816f66426a9d4f5b8599403b6a9008bd"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-9zdj"
I20260812 06:20:06.472153  3078 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:06.473176  3311 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:20:06.473462  3078 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:06.473559  3078 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/master-0-root
uuid: "816f66426a9d4f5b8599403b6a9008bd"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-9zdj"
I20260812 06:20:06.473683  3078 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-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:20:06.482717  3078 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.483197  3078 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.488224  3078 rpc_server.cc:307] RPC server started. Bound to: 127.3.1.190:41421
I20260812 06:20:06.491359  3372 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.1.190:41421 every 8 connection(s)
I20260812 06:20:06.491959  3373 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:20:06.496152  3373 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd: Bootstrap starting.
I20260812 06:20:06.497331  3373 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.508561  3373 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd: No bootstrap required, opened a new log
I20260812 06:20:06.509125  3373 raft_consensus.cc:359] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER }
I20260812 06:20:06.509260  3373 raft_consensus.cc:385] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.509307  3373 raft_consensus.cc:740] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 816f66426a9d4f5b8599403b6a9008bd, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.509497  3373 consensus_queue.cc:260] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [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: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER }
I20260812 06:20:06.509596  3373 raft_consensus.cc:399] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.509667  3373 raft_consensus.cc:493] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.509734  3373 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.510600  3373 raft_consensus.cc:515] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER }
I20260812 06:20:06.510771  3373 leader_election.cc:304] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [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: 816f66426a9d4f5b8599403b6a9008bd; no voters: 
I20260812 06:20:06.511018  3373 leader_election.cc:290] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.511233  3377 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.511525  3377 raft_consensus.cc:697] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 1 LEADER]: Becoming Leader. State: Replica: 816f66426a9d4f5b8599403b6a9008bd, State: Running, Role: LEADER
I20260812 06:20:06.511667  3373 sys_catalog.cc:565] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.511700  3377 consensus_queue.cc:237] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [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: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER }
I20260812 06:20:06.512200  3378 sys_catalog.cc:455] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "816f66426a9d4f5b8599403b6a9008bd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER } }
I20260812 06:20:06.512307  3378 sys_catalog.cc:458] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.512217  3379 sys_catalog.cc:455] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [sys.catalog]: SysCatalogTable state changed. Reason: New leader 816f66426a9d4f5b8599403b6a9008bd. Latest consensus state: current_term: 1 leader_uuid: "816f66426a9d4f5b8599403b6a9008bd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "816f66426a9d4f5b8599403b6a9008bd" member_type: VOTER } }
I20260812 06:20:06.512547  3379 sys_catalog.cc:458] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.512603  3383 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.513417  3383 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.513825  3078 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.515592  3383 catalog_manager.cc:1383] Generated new cluster ID: 5e898240ce7b4e1ca9b613d176b709b7
I20260812 06:20:06.515654  3383 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.529363  3383 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.530114  3383 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.539316  3383 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd: Generated new TSK 0
I20260812 06:20:06.539566  3383 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.546669  3078 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.549299  3407 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:20:06.549299  3405 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:20:06.549543  3078 server_base.cc:1061] running on GCE node
W20260812 06:20:06.549350  3403 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:20:06.549917  3078 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.549991  3078 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:20:06.550019  3078 hybrid_clock.cc:648] HybridClock initialized: now 1786515606550018 us; error 0 us; skew 500 ppm
I20260812 06:20:06.551074  3078 webserver.cc:533] Webserver started at http://127.3.1.129:45779/ using document root <none> and password file <none>
I20260812 06:20:06.551285  3078 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.551366  3078 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.551484  3078 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.551971  3078 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/instance:
uuid: "33acb08bf93c4123b5b47397e4a33dbc"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-9zdj"
I20260812 06:20:06.554141  3078 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:06.555523  3412 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:20:06.555980  3078 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.556113  3078 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root
uuid: "33acb08bf93c4123b5b47397e4a33dbc"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-9zdj"
I20260812 06:20:06.556229  3078 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-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:20:06.572969  3078 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.573464  3078 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.573932  3078 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.574460  3078 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.574525  3078 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.574587  3078 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.574649  3078 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.580086  3078 rpc_server.cc:307] RPC server started. Bound to: 127.3.1.129:41399
I20260812 06:20:06.580108  3487 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.1.129:41399 every 8 connection(s)
I20260812 06:20:06.593323  3488 heartbeater.cc:344] Connected to a master server at 127.3.1.190:41421
I20260812 06:20:06.593473  3488 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.593811  3488 heartbeater.cc:507] Master 127.3.1.190:41421 requested a full tablet report, sending...
I20260812 06:20:06.594621  3332 ts_manager.cc:194] Registered new tserver with Master: 33acb08bf93c4123b5b47397e4a33dbc (127.3.1.129:41399)
I20260812 06:20:06.595440  3078 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014824386s
I20260812 06:20:06.595458  3332 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42538
I20260812 06:20:06.603348  3332 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42540:
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:20:06.613509  3447 tablet_service.cc:1511] Processing CreateTablet for tablet f7d4d0aaf5d4409e9148ef0a94eea00b (DEFAULT_TABLE table=heavy-update-compaction-test [id=0f32b9fe4c7d436db7027b444465389f]), partition=
I20260812 06:20:06.613880  3447 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f7d4d0aaf5d4409e9148ef0a94eea00b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.616427  3504 tablet_bootstrap.cc:492] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Bootstrap starting.
I20260812 06:20:06.617389  3504 tablet_bootstrap.cc:654] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.618835  3504 tablet_bootstrap.cc:492] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: No bootstrap required, opened a new log
I20260812 06:20:06.618947  3504 ts_tablet_manager.cc:1403] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:06.619575  3504 raft_consensus.cc:359] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33acb08bf93c4123b5b47397e4a33dbc" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 41399 } }
I20260812 06:20:06.619679  3504 raft_consensus.cc:385] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.619704  3504 raft_consensus.cc:740] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 33acb08bf93c4123b5b47397e4a33dbc, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.619884  3504 consensus_queue.cc:260] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [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: "33acb08bf93c4123b5b47397e4a33dbc" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 41399 } }
I20260812 06:20:06.619976  3504 raft_consensus.cc:399] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.620034  3504 raft_consensus.cc:493] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.620090  3504 raft_consensus.cc:3060] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.620919  3504 raft_consensus.cc:515] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33acb08bf93c4123b5b47397e4a33dbc" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 41399 } }
I20260812 06:20:06.621081  3504 leader_election.cc:304] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [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: 33acb08bf93c4123b5b47397e4a33dbc; no voters: 
I20260812 06:20:06.621364  3504 leader_election.cc:290] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.621667  3506 raft_consensus.cc:2804] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.621773  3504 ts_tablet_manager.cc:1434] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:06.621804  3488 heartbeater.cc:499] Master 127.3.1.190:41421 was elected leader, sending a full tablet report...
I20260812 06:20:06.621779  3506 raft_consensus.cc:697] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 1 LEADER]: Becoming Leader. State: Replica: 33acb08bf93c4123b5b47397e4a33dbc, State: Running, Role: LEADER
I20260812 06:20:06.622030  3506 consensus_queue.cc:237] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [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: "33acb08bf93c4123b5b47397e4a33dbc" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 41399 } }
I20260812 06:20:06.623610  3330 catalog_manager.cc:5719] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc reported cstate change: term changed from 0 to 1, leader changed from <none> to 33acb08bf93c4123b5b47397e4a33dbc (127.3.1.129). New cstate: current_term: 1 leader_uuid: "33acb08bf93c4123b5b47397e4a33dbc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33acb08bf93c4123b5b47397e4a33dbc" member_type: VOTER last_known_addr { host: "127.3.1.129" port: 41399 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.689368  3078 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.015s	sys 0.008s
I20260812 06:20:06.831303  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=15.086190
I20260812 06:20:06.979735  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.148s	user 0.114s	sys 0.032s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1099,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37855,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:20:06.980428  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): free 20743880 bytes of WAL
I20260812 06:20:06.980670  3418 log_reader.cc:385] T f7d4d0aaf5d4409e9148ef0a94eea00b: removed 2 log segments from log reader
I20260812 06:20:06.980715  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000001 (ops 1-6)
I20260812 06:20:06.980746  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000002 (ops 7-11)
I20260812 06:20:06.985426  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:06.985838  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:07.002478  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.002946  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): 12719218 bytes on disk
I20260812 06:20:07.003387  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.003798  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:07.153532  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.150s	user 0.101s	sys 0.048s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":11298,"lbm_reads_lt_1ms":454,"lbm_write_time_us":27995,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":432,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":362,"threads_started":5,"update_count":1950}
I20260812 06:20:07.154155  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=11.118625
I20260812 06:20:07.187906  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.034s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14829,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.188536  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:07.202553  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4601,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.203254  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:07.338059  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.135s	user 0.108s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":456,"lbm_read_time_us":9674,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24732,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:20:07.338766  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:07.386535  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.048s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18863,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.387148  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:07.399379  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.400038  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:07.536068  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.136s	user 0.103s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":9975,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26077,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:20:07.536767  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:07.600436  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.063s	user 0.032s	sys 0.026s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":26082,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.601099  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:07.612625  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.613178  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:07.780872  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.168s	user 0.107s	sys 0.060s 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":427,"lbm_read_time_us":12511,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26658,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.781478  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:07.827502  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.046s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16698,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.828173  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:07.844879  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6275,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.845688  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:07.985484  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.139s	user 0.110s	sys 0.029s 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":650,"lbm_read_time_us":12191,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25764,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:20:07.986500  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:08.037367  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.051s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19844,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":1500}
I20260812 06:20:08.038041  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:08.051620  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.052441  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:08.185912  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.133s	user 0.102s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":9251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27850,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:20:08.186571  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:08.249148  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.062s	user 0.026s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18622,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.249780  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:08.261587  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.262280  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:08.419571  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.157s	user 0.111s	sys 0.046s 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":725,"lbm_read_time_us":12618,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23453,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.420373  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:08.462677  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.042s	user 0.016s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19577,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.463336  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:08.480808  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.481388  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:08.512336  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1661,"drs_written":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1537,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:08.513159  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): free 124257246 bytes of WAL
I20260812 06:20:08.513411  3418 log_reader.cc:385] T f7d4d0aaf5d4409e9148ef0a94eea00b: removed 12 log segments from log reader
I20260812 06:20:08.513450  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000003 (ops 12-16)
I20260812 06:20:08.513480  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000004 (ops 17-21)
I20260812 06:20:08.513520  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000005 (ops 22-26)
I20260812 06:20:08.513559  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000006 (ops 27-31)
I20260812 06:20:08.513604  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000007 (ops 32-36)
I20260812 06:20:08.513717  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000008 (ops 37-41)
I20260812 06:20:08.513758  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000009 (ops 42-46)
I20260812 06:20:08.513801  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000010 (ops 47-51)
I20260812 06:20:08.513845  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000011 (ops 52-56)
I20260812 06:20:08.513885  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000012 (ops 57-61)
I20260812 06:20:08.513921  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000013 (ops 62-66)
I20260812 06:20:08.513959  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000014 (ops 67-70)
I20260812 06:20:08.544186  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:08.544853  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): 482 bytes on disk
I20260812 06:20:08.545523  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.546104  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=6.157687
I20260812 06:20:08.576951  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.031s	user 0.017s	sys 0.011s Metrics: {"bytes_written":7712789,"delete_count":0,"lbm_write_time_us":8698,"lbm_writes_lt_1ms":191,"reinsert_count":0,"update_count":940}
I20260812 06:20:08.577831  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:08.799410  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.221s	user 0.136s	sys 0.084s Metrics: {"cfile_cache_miss":621,"cfile_cache_miss_bytes":28384935,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":311,"lbm_read_time_us":15831,"lbm_reads_lt_1ms":653,"lbm_write_time_us":38237,"lbm_writes_lt_1ms":631,"mutex_wait_us":83,"peak_mem_usage":74009668,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":87,"threads_started":1,"update_count":2940}
I20260812 06:20:08.800160  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=15.087375
I20260812 06:20:08.861485  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.061s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16902198,"delete_count":0,"lbm_write_time_us":21851,"lbm_writes_lt_1ms":415,"reinsert_count":0,"update_count":2060}
I20260812 06:20:08.862269  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=5.165500
I20260812 06:20:08.884582  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.022s	user 0.016s	sys 0.004s Metrics: {"bytes_written":6933329,"delete_count":0,"lbm_write_time_us":9442,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:20:08.885371  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:08.891649  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {"bytes_written":1271927,"delete_count":0,"lbm_write_time_us":1605,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:20:08.892549  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:09.113453  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.221s	user 0.148s	sys 0.068s Metrics: {"cfile_cache_miss":645,"cfile_cache_miss_bytes":29369449,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1055,"lbm_read_time_us":15472,"lbm_reads_lt_1ms":685,"lbm_write_time_us":35499,"lbm_writes_lt_1ms":655,"mutex_wait_us":299,"peak_mem_usage":77075276,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":3060}
I20260812 06:20:09.114226  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=16.079562
I20260812 06:20:09.169499  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.055s	user 0.031s	sys 0.015s Metrics: {"bytes_written":17804726,"delete_count":0,"lbm_write_time_us":22497,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:20:09.170258  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.196750
I20260812 06:20:09.181092  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":3665,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:20:09.181592  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:09.193238  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.193847  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:09.394284  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.200s	user 0.152s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877190,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":351,"lbm_read_time_us":14838,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32176,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25600,"update_count":3000}
I20260812 06:20:09.397436  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=15.087375
I20260812 06:20:09.453349  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.055s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":25426,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:20:09.454176  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:09.470363  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.016s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.470965  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:09.650117  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.179s	user 0.119s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":12786,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29113,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31360,"update_count":2500}
I20260812 06:20:09.650928  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:09.716060  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.065s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.716876  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:09.738653  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.022s	user 0.016s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.739399  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:09.923010  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.183s	user 0.131s	sys 0.052s 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":300,"lbm_read_time_us":12356,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31350,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:09.923714  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:09.985893  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.062s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21107,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.986542  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:10.003029  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.003587  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:10.037202  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1741,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:10.038084  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): 463 bytes on disk
I20260812 06:20:10.038558  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.039077  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:10.221848  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.183s	user 0.130s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":379,"lbm_read_time_us":12337,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31279,"lbm_writes_lt_1ms":543,"mutex_wait_us":104,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:10.222517  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): free 121006458 bytes of WAL
I20260812 06:20:10.222795  3418 log_reader.cc:385] T f7d4d0aaf5d4409e9148ef0a94eea00b: removed 12 log segments from log reader
I20260812 06:20:10.222874  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000015 (ops 71-75)
I20260812 06:20:10.222976  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000016 (ops 76-80)
I20260812 06:20:10.223039  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000017 (ops 81-85)
I20260812 06:20:10.223094  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000018 (ops 86-90)
I20260812 06:20:10.223137  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000019 (ops 91-94)
I20260812 06:20:10.223188  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000020 (ops 95-99)
I20260812 06:20:10.223233  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000021 (ops 100-104)
I20260812 06:20:10.223284  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000022 (ops 105-109)
I20260812 06:20:10.223325  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000023 (ops 110-114)
I20260812 06:20:10.223403  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000024 (ops 115-119)
I20260812 06:20:10.223444  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000025 (ops 120-124)
I20260812 06:20:10.223496  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000026 (ops 125-129)
I20260812 06:20:10.251724  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.029s	user 0.003s	sys 0.024s Metrics: {}
I20260812 06:20:10.252236  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:10.311721  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.059s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21777,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.312536  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:10.342104  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.029s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:10.342636  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:10.353502  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.354092  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:10.563546  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.209s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":752,"lbm_read_time_us":15090,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34834,"lbm_writes_lt_1ms":643,"mutex_wait_us":372,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:20:10.564525  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:10.623528  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.059s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.624418  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:10.655421  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.030s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.655946  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:10.667579  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.668156  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:10.895407  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.227s	user 0.138s	sys 0.089s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877216,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":435,"lbm_read_time_us":14725,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40603,"lbm_writes_lt_1ms":643,"mutex_wait_us":88,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:20:10.896193  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:10.955999  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.060s	user 0.017s	sys 0.036s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24865,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.956735  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:11.135833  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.179s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":564,"lbm_read_time_us":11360,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29630,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:20:11.136421  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:11.201040  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.064s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":30466,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.201797  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:11.214805  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.215575  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:11.423347  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.208s	user 0.153s	sys 0.044s 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":770,"lbm_read_time_us":17208,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31296,"lbm_writes_lt_1ms":543,"mutex_wait_us":266,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:11.423995  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=11.118625
I20260812 06:20:11.466722  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.043s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17492,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:11.467665  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:11.487605  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.488500  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:11.503364  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5876,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.503875  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:11.679836  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.176s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":884,"lbm_read_time_us":11500,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32481,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":2500}
I20260812 06:20:11.680661  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=14.095187
I20260812 06:20:11.735916  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.055s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21681,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.736514  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=2.188937
I20260812 06:20:11.749388  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.750136  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:11.784950  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushMRSOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.035s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1817,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1719,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:11.785821  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): free 133024646 bytes of WAL
I20260812 06:20:11.786085  3418 log_reader.cc:385] T f7d4d0aaf5d4409e9148ef0a94eea00b: removed 13 log segments from log reader
I20260812 06:20:11.786134  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000027 (ops 130-134)
I20260812 06:20:11.786191  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000028 (ops 135-138)
I20260812 06:20:11.786243  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000029 (ops 139-143)
I20260812 06:20:11.786315  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000030 (ops 144-148)
I20260812 06:20:11.786371  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000031 (ops 149-153)
I20260812 06:20:11.786418  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000032 (ops 154-158)
I20260812 06:20:11.786468  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000033 (ops 159-163)
I20260812 06:20:11.786511  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000034 (ops 164-168)
I20260812 06:20:11.786559  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000035 (ops 169-173)
I20260812 06:20:11.786599  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000036 (ops 174-178)
I20260812 06:20:11.786641  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000037 (ops 179-183)
I20260812 06:20:11.786686  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000038 (ops 184-188)
I20260812 06:20:11.786732  3418 log.cc:1079] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: Deleting log segment in path: /tmp/dist-test-taskwadGDx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600585850-3078-0/minicluster-data/ts-0-root/wals/f7d4d0aaf5d4409e9148ef0a94eea00b/wal-000000039 (ops 189-193)
I20260812 06:20:11.818663  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: LogGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:11.819149  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b): 482 bytes on disk
I20260812 06:20:11.819825  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: UndoDeltaBlockGCOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.820465  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=6.157687
I20260812 06:20:11.855882  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.035s	user 0.005s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10179,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:11.856451  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=1.000000
I20260812 06:20:11.993073  3078 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.304s	user 1.898s	sys 0.181s
I20260812 06:20:12.079104  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: MajorDeltaCompactionOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.222s	user 0.166s	sys 0.055s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1546,"lbm_read_time_us":16821,"lbm_reads_lt_1ms":761,"lbm_write_time_us":36946,"lbm_writes_lt_1ms":743,"mutex_wait_us":708,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22016,"thread_start_us":130,"threads_started":1,"update_count":3500}
I20260812 06:20:12.079974  3489 maintenance_manager.cc:419] P 33acb08bf93c4123b5b47397e4a33dbc: Scheduling FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b): perf score=10.126437
I20260812 06:20:12.092005  3078 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.003s	sys 0.000s
I20260812 06:20:12.092670  3078 tablet_server.cc:179] TabletServer@127.3.1.129:0 shutting down...
I20260812 06:20:12.116186  3418 maintenance_manager.cc:643] P 33acb08bf93c4123b5b47397e4a33dbc: FlushDeltaMemStoresOp(f7d4d0aaf5d4409e9148ef0a94eea00b) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16265,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.116791  3078 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:12.117050  3078 tablet_replica.cc:333] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc: stopping tablet replica
I20260812 06:20:12.117213  3078 raft_consensus.cc:2243] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:12.130448  3078 raft_consensus.cc:2272] T f7d4d0aaf5d4409e9148ef0a94eea00b P 33acb08bf93c4123b5b47397e4a33dbc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:12.134641  3078 tablet_server.cc:196] TabletServer@127.3.1.129:0 shutdown complete.
I20260812 06:20:12.137988  3078 master.cc:562] Master@127.3.1.190:41421 shutting down...
I20260812 06:20:12.141719  3078 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:12.141966  3078 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:12.142068  3078 tablet_replica.cc:333] T 00000000000000000000000000000000 P 816f66426a9d4f5b8599403b6a9008bd: stopping tablet replica
I20260812 06:20:12.154703  3078 master.cc:584] Master@127.3.1.190:41421 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5784 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11652 ms total)

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