[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:21.673966 30106 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.102.190:33695
I20260812 06:19:21.675086 30106 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:21.675707 30106 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.682144 30115 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.682144 30111 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.682276 30106 server_base.cc:1061] running on GCE node
W20260812 06:19:21.682443 30113 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.683024 30106 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.683140 30106 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.683187 30106 hybrid_clock.cc:648] HybridClock initialized: now 1786515561683185 us; error 0 us; skew 500 ppm
I20260812 06:19:21.685086 30106 webserver.cc:533] Webserver started at http://127.29.102.190:33841/ using document root <none> and password file <none>
I20260812 06:19:21.685624 30106 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.685704 30106 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.685968 30106 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.687602 30106 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/master-0-root/instance:
uuid: "f0aded913ddf4d7fbeeede7e8d88ff25"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-mvvj"
I20260812 06:19:21.691048 30106 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:21.693115 30121 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.694074 30106 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:21.694211 30106 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/master-0-root
uuid: "f0aded913ddf4d7fbeeede7e8d88ff25"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-mvvj"
I20260812 06:19:21.694310 30106 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.714274 30106 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.714998 30106 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:21.715184 30106 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.723315 30106 rpc_server.cc:307] RPC server started. Bound to: 127.29.102.190:33695
I20260812 06:19:21.723333 30180 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.102.190:33695 every 8 connection(s)
I20260812 06:19:21.725740 30181 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.731235 30181 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: Bootstrap starting.
I20260812 06:19:21.733639 30181 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.734578 30181 log.cc:826] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:21.736364 30181 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: No bootstrap required, opened a new log
I20260812 06:19:21.739208 30181 raft_consensus.cc:359] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER }
I20260812 06:19:21.739383 30181 raft_consensus.cc:385] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.739456 30181 raft_consensus.cc:740] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f0aded913ddf4d7fbeeede7e8d88ff25, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.740197 30181 consensus_queue.cc:260] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [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: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER }
I20260812 06:19:21.740373 30181 raft_consensus.cc:399] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.740458 30181 raft_consensus.cc:493] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.740605 30181 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.741555 30181 raft_consensus.cc:515] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER }
I20260812 06:19:21.742025 30181 leader_election.cc:304] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [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: f0aded913ddf4d7fbeeede7e8d88ff25; no voters: 
I20260812 06:19:21.742406 30181 leader_election.cc:290] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.742626 30184 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.742902 30184 raft_consensus.cc:697] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 1 LEADER]: Becoming Leader. State: Replica: f0aded913ddf4d7fbeeede7e8d88ff25, State: Running, Role: LEADER
I20260812 06:19:21.743338 30184 consensus_queue.cc:237] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [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: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER }
I20260812 06:19:21.743531 30181 sys_catalog.cc:565] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:21.745388 30186 sys_catalog.cc:455] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f0aded913ddf4d7fbeeede7e8d88ff25. Latest consensus state: current_term: 1 leader_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER } }
I20260812 06:19:21.745437 30185 sys_catalog.cc:455] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0aded913ddf4d7fbeeede7e8d88ff25" member_type: VOTER } }
I20260812 06:19:21.745518 30186 sys_catalog.cc:458] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.745537 30185 sys_catalog.cc:458] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.746094 30106 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:21.748112 30200 catalog_manager.cc:1594] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:21.748193 30200 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:21.748273 30198 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:21.749020 30198 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:21.753986 30198 catalog_manager.cc:1383] Generated new cluster ID: f93ae002dabf44dfa4bf738588059787
I20260812 06:19:21.754065 30198 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:21.774318 30198 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:21.775380 30198 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:21.785352 30198 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: Generated new TSK 0
I20260812 06:19:21.786037 30198 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:21.811210 30106 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.814725 30204 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.814806 30205 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.814834 30209 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.815124 30106 server_base.cc:1061] running on GCE node
I20260812 06:19:21.815290 30106 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.815341 30106 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.815404 30106 hybrid_clock.cc:648] HybridClock initialized: now 1786515561815403 us; error 0 us; skew 500 ppm
I20260812 06:19:21.816402 30106 webserver.cc:533] Webserver started at http://127.29.102.129:38725/ using document root <none> and password file <none>
I20260812 06:19:21.816606 30106 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.816656 30106 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.816756 30106 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.817178 30106 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/instance:
uuid: "1252d0a082864b56944662797351692e"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-mvvj"
I20260812 06:19:21.818742 30106 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:21.819746 30215 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.820022 30106 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:21.820101 30106 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root
uuid: "1252d0a082864b56944662797351692e"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-mvvj"
I20260812 06:19:21.820192 30106 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.849251 30106 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.849709 30106 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.850226 30106 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:21.851246 30106 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:21.851310 30106 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.851356 30106 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:21.851418 30106 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.858253 30106 rpc_server.cc:307] RPC server started. Bound to: 127.29.102.129:33423
I20260812 06:19:21.858314 30287 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.102.129:33423 every 8 connection(s)
I20260812 06:19:21.872265 30288 heartbeater.cc:344] Connected to a master server at 127.29.102.190:33695
I20260812 06:19:21.872607 30288 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:21.873088 30288 heartbeater.cc:507] Master 127.29.102.190:33695 requested a full tablet report, sending...
I20260812 06:19:21.874643 30141 ts_manager.cc:194] Registered new tserver with Master: 1252d0a082864b56944662797351692e (127.29.102.129:33423)
I20260812 06:19:21.875567 30106 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016449303s
I20260812 06:19:21.876174 30141 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33194
I20260812 06:19:21.885805 30141 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33210:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:21.899637 30249 tablet_service.cc:1511] Processing CreateTablet for tablet aa40141022a642838b0c8410dfc0813c (DEFAULT_TABLE table=heavy-update-compaction-test [id=d387c0d109dc42f6aba60330675e1f44]), partition=
I20260812 06:19:21.900146 30249 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aa40141022a642838b0c8410dfc0813c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.902878 30300 tablet_bootstrap.cc:492] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Bootstrap starting.
I20260812 06:19:21.904018 30300 tablet_bootstrap.cc:654] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.905179 30300 tablet_bootstrap.cc:492] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: No bootstrap required, opened a new log
I20260812 06:19:21.905260 30300 ts_tablet_manager.cc:1403] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:21.905740 30300 raft_consensus.cc:359] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1252d0a082864b56944662797351692e" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 33423 } }
I20260812 06:19:21.905838 30300 raft_consensus.cc:385] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.905860 30300 raft_consensus.cc:740] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1252d0a082864b56944662797351692e, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.906039 30300 consensus_queue.cc:260] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [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: "1252d0a082864b56944662797351692e" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 33423 } }
I20260812 06:19:21.906126 30300 raft_consensus.cc:399] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.906181 30300 raft_consensus.cc:493] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.906237 30300 raft_consensus.cc:3060] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.906945 30300 raft_consensus.cc:515] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1252d0a082864b56944662797351692e" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 33423 } }
I20260812 06:19:21.907091 30300 leader_election.cc:304] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [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: 1252d0a082864b56944662797351692e; no voters: 
I20260812 06:19:21.907339 30300 leader_election.cc:290] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.907428 30302 raft_consensus.cc:2804] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.907689 30300 ts_tablet_manager.cc:1434] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:21.907785 30302 raft_consensus.cc:697] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 1 LEADER]: Becoming Leader. State: Replica: 1252d0a082864b56944662797351692e, State: Running, Role: LEADER
I20260812 06:19:21.907933 30302 consensus_queue.cc:237] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [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: "1252d0a082864b56944662797351692e" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 33423 } }
I20260812 06:19:21.908150 30288 heartbeater.cc:499] Master 127.29.102.190:33695 was elected leader, sending a full tablet report...
I20260812 06:19:21.910588 30141 catalog_manager.cc:5719] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e reported cstate change: term changed from 0 to 1, leader changed from <none> to 1252d0a082864b56944662797351692e (127.29.102.129). New cstate: current_term: 1 leader_uuid: "1252d0a082864b56944662797351692e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1252d0a082864b56944662797351692e" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 33423 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:21.973623 30106 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.021s	sys 0.004s
I20260812 06:19:22.109663 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushMRSOp(aa40141022a642838b0c8410dfc0813c): perf score=19.054940
I20260812 06:19:22.263888 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushMRSOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.154s	user 0.129s	sys 0.020s Metrics: {"bytes_written":9435801,"cfile_init":1,"compiler_manager_pool.queue_time_us":237,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1162,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36894,"lbm_writes_lt_1ms":687,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":157056,"thread_start_us":167,"threads_started":1,"update_count":1150}
I20260812 06:19:22.265697 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling LogGCOp(aa40141022a642838b0c8410dfc0813c): free 20743880 bytes of WAL
I20260812 06:19:22.266619 30221 log_reader.cc:385] T aa40141022a642838b0c8410dfc0813c: removed 2 log segments from log reader
I20260812 06:19:22.266731 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000001 (ops 1-6)
I20260812 06:19:22.266809 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000002 (ops 7-11)
I20260812 06:19:22.272578 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: LogGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:22.273056 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:22.295356 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.022s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:19:22.295778 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c): 16411392 bytes on disk
I20260812 06:19:22.296422 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.296813 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:22.309917 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.310354 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:22.444823 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.134s	user 0.110s	sys 0.020s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672365,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":661,"lbm_read_time_us":7987,"lbm_reads_lt_1ms":469,"lbm_write_time_us":23449,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":335,"threads_started":5,"update_count":2000}
I20260812 06:19:22.445366 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:22.491586 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.046s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14803,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.492131 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:22.502693 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.503207 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:22.626648 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.123s	user 0.101s	sys 0.020s 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":660,"lbm_read_time_us":7160,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23731,"lbm_writes_lt_1ms":443,"mutex_wait_us":308,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:22.627296 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:22.674165 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.047s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18377,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.674681 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:22.685916 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.686481 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:22.814409 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.128s	user 0.101s	sys 0.024s 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":923,"lbm_read_time_us":8781,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25855,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:22.815124 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:22.865685 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.050s	user 0.015s	sys 0.033s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16467,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.866446 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:22.884491 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.885017 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.039320 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.154s	user 0.103s	sys 0.041s 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":353,"lbm_read_time_us":10496,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22812,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:23.039899 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:23.086778 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.047s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18720,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.087348 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:23.099341 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.099790 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.220731 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.121s	user 0.096s	sys 0.025s 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":579,"lbm_read_time_us":8479,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22388,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.221414 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:23.259305 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.038s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.259908 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:23.275264 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.275887 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.410125 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.134s	user 0.099s	sys 0.035s 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":1200,"lbm_read_time_us":9991,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26242,"lbm_writes_lt_1ms":443,"mutex_wait_us":321,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:23.410662 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:23.458891 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.048s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16255,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.459617 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:23.473445 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.474288 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushMRSOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.502106 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushMRSOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1397,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1811,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:23.502888 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling LogGCOp(aa40141022a642838b0c8410dfc0813c): free 112239311 bytes of WAL
I20260812 06:19:23.503103 30221 log_reader.cc:385] T aa40141022a642838b0c8410dfc0813c: removed 11 log segments from log reader
I20260812 06:19:23.503160 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000003 (ops 12-16)
I20260812 06:19:23.503213 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000004 (ops 17-21)
I20260812 06:19:23.503268 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000005 (ops 22-26)
I20260812 06:19:23.503309 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000006 (ops 27-31)
I20260812 06:19:23.503343 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000007 (ops 32-36)
I20260812 06:19:23.503382 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000008 (ops 37-41)
I20260812 06:19:23.503418 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000009 (ops 42-46)
I20260812 06:19:23.503454 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000010 (ops 47-50)
I20260812 06:19:23.503490 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000011 (ops 51-55)
I20260812 06:19:23.503526 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000012 (ops 56-60)
I20260812 06:19:23.503561 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000013 (ops 61-65)
I20260812 06:19:23.528105 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: LogGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:23.528551 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c): 447 bytes on disk
I20260812 06:19:23.529210 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.529873 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=3.181125
I20260812 06:19:23.541495 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.541916 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:23.552211 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.552984 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.733100 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.180s	user 0.153s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":458,"lbm_read_time_us":12998,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36402,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:23.733858 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:23.781639 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.048s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.782362 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:23.794392 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.795099 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:23.961225 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.166s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":11015,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29811,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:19:23.961989 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:24.006003 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.044s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19382,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.006661 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:24.166378 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.160s	user 0.099s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":201,"lbm_read_time_us":10942,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27171,"lbm_writes_lt_1ms":443,"mutex_wait_us":98,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:24.167300 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=11.118625
I20260812 06:19:24.204813 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.037s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16072,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.205667 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:24.223094 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5100,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.223608 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:24.349838 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.126s	user 0.110s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":7107,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25074,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:24.350476 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:24.389562 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16859,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.390164 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:24.405944 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5803,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.406544 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:24.544026 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.137s	user 0.107s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":291,"lbm_read_time_us":10252,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23070,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:24.544605 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:24.587682 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.043s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19098,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.588215 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:24.602154 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.602864 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:24.728878 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.126s	user 0.085s	sys 0.040s 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":1014,"lbm_read_time_us":9148,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24199,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":54912,"update_count":2000}
I20260812 06:19:24.729589 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=10.126437
I20260812 06:19:24.774880 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.045s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.775611 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:24.786720 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4420,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.787189 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:24.944907 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.158s	user 0.119s	sys 0.035s 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":428,"lbm_read_time_us":10489,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25582,"lbm_writes_lt_1ms":443,"mutex_wait_us":131,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:24.945796 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=11.118625
I20260812 06:19:24.988721 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.042s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":18579,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.989430 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.004212 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4647,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.004768 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushMRSOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:25.061924 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushMRSOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.057s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1342,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1859,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:25.062744 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling LogGCOp(aa40141022a642838b0c8410dfc0813c): free 129320505 bytes of WAL
I20260812 06:19:25.063019 30221 log_reader.cc:385] T aa40141022a642838b0c8410dfc0813c: removed 13 log segments from log reader
I20260812 06:19:25.063079 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000014 (ops 66-70)
I20260812 06:19:25.063120 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000015 (ops 71-74)
I20260812 06:19:25.063155 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000016 (ops 75-79)
I20260812 06:19:25.063179 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000017 (ops 80-84)
I20260812 06:19:25.063205 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000018 (ops 85-89)
I20260812 06:19:25.063234 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000019 (ops 90-94)
I20260812 06:19:25.063263 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000020 (ops 95-98)
I20260812 06:19:25.063297 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000021 (ops 99-103)
I20260812 06:19:25.063328 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000022 (ops 104-108)
I20260812 06:19:25.063354 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000023 (ops 109-113)
I20260812 06:19:25.063383 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000024 (ops 114-118)
I20260812 06:19:25.063409 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000025 (ops 119-123)
I20260812 06:19:25.063452 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000026 (ops 124-128)
I20260812 06:19:25.092757 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: LogGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:25.093184 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=6.157687
I20260812 06:19:25.120158 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.027s	user 0.006s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9105,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:25.120666 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c): 493 bytes on disk
I20260812 06:19:25.121127 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.121701 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.131747 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.132237 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:25.343004 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.211s	user 0.122s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1528,"lbm_read_time_us":14119,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34989,"lbm_writes_lt_1ms":743,"mutex_wait_us":342,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:25.343685 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:25.395362 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.051s	user 0.016s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.395934 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.418699 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.023s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.419134 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.429723 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.430166 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:25.616287 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.186s	user 0.122s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":14003,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31619,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:25.617017 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:25.671945 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.055s	user 0.044s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20877,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.672430 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.684944 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.685441 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:25.877677 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.192s	user 0.132s	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":213,"lbm_read_time_us":13561,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31765,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:25.878579 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:25.938717 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.060s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24010,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.939272 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:25.951134 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s 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:19:25.952582 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:26.129833 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.177s	user 0.104s	sys 0.065s 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":653,"lbm_read_time_us":13284,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30072,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:26.130370 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=14.095187
I20260812 06:19:26.190095 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.060s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.190690 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:26.203022 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.203464 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:26.384459 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.181s	user 0.109s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":466,"lbm_read_time_us":12777,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29914,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:19:26.385251 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=11.118625
I20260812 06:19:26.417377 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.032s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":13057,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:26.417891 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:26.452777 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.035s	user 0.008s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5251,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.453359 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:26.469673 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.470376 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushMRSOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:26.516254 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushMRSOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.046s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1338,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1652,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:26.516987 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling LogGCOp(aa40141022a642838b0c8410dfc0813c): free 124257449 bytes of WAL
I20260812 06:19:26.517216 30221 log_reader.cc:385] T aa40141022a642838b0c8410dfc0813c: removed 12 log segments from log reader
I20260812 06:19:26.517261 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000027 (ops 129-133)
I20260812 06:19:26.517316 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000028 (ops 134-138)
I20260812 06:19:26.517361 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000029 (ops 139-143)
I20260812 06:19:26.517390 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000030 (ops 144-148)
I20260812 06:19:26.517428 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000031 (ops 149-153)
I20260812 06:19:26.517465 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000032 (ops 154-158)
I20260812 06:19:26.517505 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000033 (ops 159-163)
I20260812 06:19:26.517531 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000034 (ops 164-168)
I20260812 06:19:26.517573 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000035 (ops 169-172)
I20260812 06:19:26.517614 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000036 (ops 173-177)
I20260812 06:19:26.517653 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000037 (ops 178-182)
I20260812 06:19:26.517694 30221 log.cc:1079] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/aa40141022a642838b0c8410dfc0813c/wal-000000038 (ops 183-187)
I20260812 06:19:26.543044 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: LogGCOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:26.543455 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=3.181125
I20260812 06:19:26.560724 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.017s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:26.561178 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=2.188937
I20260812 06:19:26.571017 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3620,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.571473 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c): 447 bytes on disk
I20260812 06:19:26.571954 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: UndoDeltaBlockGCOp(aa40141022a642838b0c8410dfc0813c) 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:19:26.572508 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:26.798702 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.226s	user 0.161s	sys 0.063s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":964,"lbm_read_time_us":14395,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38102,"lbm_writes_lt_1ms":743,"mutex_wait_us":48,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:19:26.800499 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=16.079562
I20260812 06:19:26.845513 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.045s	user 0.035s	sys 0.008s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":20059,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:19:26.846045 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c): perf score=1.196750
I20260812 06:19:26.863940 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: FlushDeltaMemStoresOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:26.864454 30289 maintenance_manager.cc:419] P 1252d0a082864b56944662797351692e: Scheduling MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c): perf score=1.000000
I20260812 06:19:26.880681 30106 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.907s	user 1.844s	sys 0.120s
I20260812 06:19:26.962000 30106 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:19:26.962621 30106 tablet_server.cc:179] TabletServer@127.29.102.129:0 shutting down...
I20260812 06:19:27.023022 30221 maintenance_manager.cc:643] P 1252d0a082864b56944662797351692e: MajorDeltaCompactionOp(aa40141022a642838b0c8410dfc0813c) complete. Timing: real 0.158s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774658,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":13931,"lbm_reads_lt_1ms":560,"lbm_write_time_us":25438,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:19:27.023802 30106 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:27.024261 30106 tablet_replica.cc:333] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e: stopping tablet replica
I20260812 06:19:27.024514 30106 raft_consensus.cc:2243] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:27.024757 30106 raft_consensus.cc:2272] T aa40141022a642838b0c8410dfc0813c P 1252d0a082864b56944662797351692e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:27.040959 30106 tablet_server.cc:196] TabletServer@127.29.102.129:0 shutdown complete.
I20260812 06:19:27.070138 30106 master.cc:562] Master@127.29.102.190:33695 shutting down...
I20260812 06:19:27.073894 30106 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:27.074105 30106 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:27.074191 30106 tablet_replica.cc:333] T 00000000000000000000000000000000 P f0aded913ddf4d7fbeeede7e8d88ff25: stopping tablet replica
I20260812 06:19:27.086678 30106 master.cc:584] Master@127.29.102.190:33695 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5500 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:27.186563 30106 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.102.190:33011
I20260812 06:19:27.187000 30106 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.189073 30324 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.189095 30322 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.189250 30106 server_base.cc:1061] running on GCE node
W20260812 06:19:27.189102 30321 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.189677 30106 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.189716 30106 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.189731 30106 hybrid_clock.cc:648] HybridClock initialized: now 1786515567189732 us; error 0 us; skew 500 ppm
I20260812 06:19:27.190477 30106 webserver.cc:533] Webserver started at http://127.29.102.190:41575/ using document root <none> and password file <none>
I20260812 06:19:27.190610 30106 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.190654 30106 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.190706 30106 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.191078 30106 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/master-0-root/instance:
uuid: "bda4ed1950bd4cc3b88a31e36e21ef01"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-mvvj"
I20260812 06:19:27.192625 30106 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:27.193557 30329 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.193840 30106 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:27.193905 30106 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/master-0-root
uuid: "bda4ed1950bd4cc3b88a31e36e21ef01"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-mvvj"
I20260812 06:19:27.193994 30106 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.212997 30106 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.213449 30106 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.217905 30106 rpc_server.cc:307] RPC server started. Bound to: 127.29.102.190:33011
I20260812 06:19:27.219341 30389 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.221740 30388 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.102.190:33011 every 8 connection(s)
I20260812 06:19:27.223106 30389 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01: Bootstrap starting.
I20260812 06:19:27.224092 30389 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.225183 30389 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01: No bootstrap required, opened a new log
I20260812 06:19:27.225656 30389 raft_consensus.cc:359] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER }
I20260812 06:19:27.225768 30389 raft_consensus.cc:385] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.225829 30389 raft_consensus.cc:740] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bda4ed1950bd4cc3b88a31e36e21ef01, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.225998 30389 consensus_queue.cc:260] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [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: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER }
I20260812 06:19:27.226094 30389 raft_consensus.cc:399] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.226137 30389 raft_consensus.cc:493] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.226192 30389 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.226912 30389 raft_consensus.cc:515] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER }
I20260812 06:19:27.227061 30389 leader_election.cc:304] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [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: bda4ed1950bd4cc3b88a31e36e21ef01; no voters: 
I20260812 06:19:27.227268 30389 leader_election.cc:290] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.227393 30393 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.227622 30393 raft_consensus.cc:697] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 1 LEADER]: Becoming Leader. State: Replica: bda4ed1950bd4cc3b88a31e36e21ef01, State: Running, Role: LEADER
I20260812 06:19:27.227770 30389 sys_catalog.cc:565] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:27.227802 30393 consensus_queue.cc:237] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [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: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER }
I20260812 06:19:27.228319 30394 sys_catalog.cc:455] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER } }
I20260812 06:19:27.228431 30394 sys_catalog.cc:458] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.228332 30396 sys_catalog.cc:455] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [sys.catalog]: SysCatalogTable state changed. Reason: New leader bda4ed1950bd4cc3b88a31e36e21ef01. Latest consensus state: current_term: 1 leader_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bda4ed1950bd4cc3b88a31e36e21ef01" member_type: VOTER } }
I20260812 06:19:27.228695 30396 sys_catalog.cc:458] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.229146 30402 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:27.229827 30402 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:27.230082 30106 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:27.231626 30402 catalog_manager.cc:1383] Generated new cluster ID: 41480cd7836d43d88ee4b14e31b6f07b
I20260812 06:19:27.231680 30402 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:27.241336 30402 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:27.241842 30402 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:27.255894 30402 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01: Generated new TSK 0
I20260812 06:19:27.256078 30402 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:27.262353 30106 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.264320 30415 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.264334 30418 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.264446 30414 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.264525 30106 server_base.cc:1061] running on GCE node
I20260812 06:19:27.264750 30106 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.264793 30106 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.264809 30106 hybrid_clock.cc:648] HybridClock initialized: now 1786515567264809 us; error 0 us; skew 500 ppm
I20260812 06:19:27.265556 30106 webserver.cc:533] Webserver started at http://127.29.102.129:46083/ using document root <none> and password file <none>
I20260812 06:19:27.265726 30106 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.265774 30106 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.265826 30106 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.266189 30106 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/instance:
uuid: "8a4969e7533b4f608677854073a95431"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-mvvj"
I20260812 06:19:27.267748 30106 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:27.268756 30425 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.268996 30106 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:27.269059 30106 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root
uuid: "8a4969e7533b4f608677854073a95431"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-mvvj"
I20260812 06:19:27.269151 30106 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.279551 30106 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.280040 30106 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.280413 30106 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:27.280886 30106 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:27.280925 30106 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.280957 30106 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:27.280973 30106 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.285501 30106 rpc_server.cc:307] RPC server started. Bound to: 127.29.102.129:45927
I20260812 06:19:27.287407 30493 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.102.129:45927 every 8 connection(s)
I20260812 06:19:27.296823 30494 heartbeater.cc:344] Connected to a master server at 127.29.102.190:33011
I20260812 06:19:27.296989 30494 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:27.297286 30494 heartbeater.cc:507] Master 127.29.102.190:33011 requested a full tablet report, sending...
I20260812 06:19:27.298097 30351 ts_manager.cc:194] Registered new tserver with Master: 8a4969e7533b4f608677854073a95431 (127.29.102.129:45927)
I20260812 06:19:27.298610 30106 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012248688s
I20260812 06:19:27.299077 30351 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50662
I20260812 06:19:27.306116 30351 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50668:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:27.315140 30455 tablet_service.cc:1511] Processing CreateTablet for tablet de1c83625ed04133b65ae7fdd282970e (DEFAULT_TABLE table=heavy-update-compaction-test [id=81130883afbd49f5a1674fdbeab80844]), partition=
I20260812 06:19:27.315402 30455 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet de1c83625ed04133b65ae7fdd282970e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.317649 30508 tablet_bootstrap.cc:492] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Bootstrap starting.
I20260812 06:19:27.318486 30508 tablet_bootstrap.cc:654] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.319455 30508 tablet_bootstrap.cc:492] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: No bootstrap required, opened a new log
I20260812 06:19:27.319572 30508 ts_tablet_manager.cc:1403] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:27.319988 30508 raft_consensus.cc:359] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a4969e7533b4f608677854073a95431" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 45927 } }
I20260812 06:19:27.320094 30508 raft_consensus.cc:385] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.320173 30508 raft_consensus.cc:740] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8a4969e7533b4f608677854073a95431, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.320329 30508 consensus_queue.cc:260] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [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: "8a4969e7533b4f608677854073a95431" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 45927 } }
I20260812 06:19:27.320441 30508 raft_consensus.cc:399] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.320487 30508 raft_consensus.cc:493] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.320540 30508 raft_consensus.cc:3060] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.321280 30508 raft_consensus.cc:515] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a4969e7533b4f608677854073a95431" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 45927 } }
I20260812 06:19:27.321421 30508 leader_election.cc:304] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [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: 8a4969e7533b4f608677854073a95431; no voters: 
I20260812 06:19:27.321619 30508 leader_election.cc:290] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.321738 30511 raft_consensus.cc:2804] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.321952 30508 ts_tablet_manager.cc:1434] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:27.321959 30511 raft_consensus.cc:697] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 1 LEADER]: Becoming Leader. State: Replica: 8a4969e7533b4f608677854073a95431, State: Running, Role: LEADER
I20260812 06:19:27.322001 30494 heartbeater.cc:499] Master 127.29.102.190:33011 was elected leader, sending a full tablet report...
I20260812 06:19:27.322193 30511 consensus_queue.cc:237] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [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: "8a4969e7533b4f608677854073a95431" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 45927 } }
I20260812 06:19:27.323542 30351 catalog_manager.cc:5719] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8a4969e7533b4f608677854073a95431 (127.29.102.129). New cstate: current_term: 1 leader_uuid: "8a4969e7533b4f608677854073a95431" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a4969e7533b4f608677854073a95431" member_type: VOTER last_known_addr { host: "127.29.102.129" port: 45927 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:27.381963 30106 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.017s	sys 0.005s
I20260812 06:19:27.537894 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushMRSOp(de1c83625ed04133b65ae7fdd282970e): perf score=19.054940
I20260812 06:19:27.704286 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushMRSOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.166s	user 0.126s	sys 0.039s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":861,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40586,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:27.705066 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling LogGCOp(de1c83625ed04133b65ae7fdd282970e): free 20290830 bytes of WAL
I20260812 06:19:27.705332 30430 log_reader.cc:385] T de1c83625ed04133b65ae7fdd282970e: removed 2 log segments from log reader
I20260812 06:19:27.705377 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000001 (ops 1-6)
I20260812 06:19:27.705425 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000002 (ops 7-10)
I20260812 06:19:27.709637 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: LogGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:27.710052 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:27.723042 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.723474 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e): 16411396 bytes on disk
I20260812 06:19:27.723958 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.724464 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:27.877496 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.153s	user 0.101s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":841,"lbm_read_time_us":10391,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26066,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":377,"threads_started":5,"update_count":2000}
I20260812 06:19:27.878233 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:27.918910 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.040s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17505,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.919414 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:27.931300 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.931727 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.061213 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.129s	user 0.106s	sys 0.021s 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":212,"lbm_read_time_us":8989,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24738,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:28.061836 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:28.106761 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.045s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21960,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.107300 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.122532 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.015s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.123077 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.243273 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.120s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":7620,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22444,"lbm_writes_lt_1ms":443,"mutex_wait_us":268,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:19:28.244087 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:28.290838 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.047s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17560,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.292281 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.309706 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.310530 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.444492 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.134s	user 0.081s	sys 0.052s 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":368,"lbm_read_time_us":7957,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26501,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:28.445232 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:28.493729 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.048s	user 0.016s	sys 0.030s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17389,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.494273 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.506712 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.507283 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.672008 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.165s	user 0.110s	sys 0.053s 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":958,"lbm_read_time_us":11621,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27754,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:19:28.672863 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:28.709951 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.037s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14195,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.710448 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.721879 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:19:28.722764 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.849731 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.127s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":698,"lbm_read_time_us":8602,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25011,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:28.850548 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=10.126437
I20260812 06:19:28.891579 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.041s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15656,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.892127 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.903079 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.903650 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushMRSOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:28.931295 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushMRSOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1397,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1578,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:28.931960 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling LogGCOp(de1c83625ed04133b65ae7fdd282970e): free 108988499 bytes of WAL
I20260812 06:19:28.932180 30430 log_reader.cc:385] T de1c83625ed04133b65ae7fdd282970e: removed 11 log segments from log reader
I20260812 06:19:28.932245 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000003 (ops 11-15)
I20260812 06:19:28.932291 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000004 (ops 16-20)
I20260812 06:19:28.932343 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000005 (ops 21-25)
I20260812 06:19:28.932381 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000006 (ops 26-30)
I20260812 06:19:28.932421 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000007 (ops 31-35)
I20260812 06:19:28.932457 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000008 (ops 36-40)
I20260812 06:19:28.932494 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000009 (ops 41-44)
I20260812 06:19:28.932530 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000010 (ops 45-49)
I20260812 06:19:28.932565 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000011 (ops 50-54)
I20260812 06:19:28.932602 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000012 (ops 55-59)
I20260812 06:19:28.932637 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000013 (ops 60-64)
I20260812 06:19:28.955864 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: LogGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.024s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:28.956326 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e): 447 bytes on disk
I20260812 06:19:28.956918 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.957453 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=3.181125
I20260812 06:19:28.974768 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:28.975255 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:28.985008 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3528,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.985477 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:29.162402 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.177s	user 0.131s	sys 0.046s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":494,"lbm_read_time_us":12132,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33530,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:29.163100 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:29.221720 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.058s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26598,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.222193 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=3.181125
I20260812 06:19:29.234115 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4418,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:29.234566 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:29.244022 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3487,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.244508 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:29.429100 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.184s	user 0.163s	sys 0.020s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":131,"lbm_read_time_us":13587,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37364,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:19:29.429908 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:29.479374 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.049s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20055,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.480026 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:29.490934 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.491457 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:29.642992 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.151s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":10399,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30017,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2500}
I20260812 06:19:29.643918 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=12.110812
I20260812 06:19:29.682509 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":13620268,"delete_count":0,"lbm_write_time_us":16275,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:19:29.683168 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.196750
I20260812 06:19:29.692998 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3476,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:29.693543 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:29.841912 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.148s	user 0.092s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672251,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":9210,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22329,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:29.842747 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:29.893172 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21765,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:29.893775 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:29.920564 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.027s	user 0.007s	sys 0.018s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.921142 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:30.099659 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.178s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":12891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28057,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:30.100592 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:30.152452 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.052s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21569,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.152920 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:30.164389 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.164830 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:30.348251 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.183s	user 0.127s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":754,"lbm_read_time_us":11484,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28566,"lbm_writes_lt_1ms":543,"mutex_wait_us":338,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:30.349191 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:30.401388 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.052s	user 0.028s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20769,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.401932 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:30.413945 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.414501 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushMRSOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:30.448372 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushMRSOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1535,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1720,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:30.449158 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling LogGCOp(de1c83625ed04133b65ae7fdd282970e): free 132571263 bytes of WAL
I20260812 06:19:30.449540 30430 log_reader.cc:385] T de1c83625ed04133b65ae7fdd282970e: removed 13 log segments from log reader
I20260812 06:19:30.449608 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000014 (ops 65-69)
I20260812 06:19:30.449661 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000015 (ops 70-74)
I20260812 06:19:30.449713 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000016 (ops 75-79)
I20260812 06:19:30.449756 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000017 (ops 80-84)
I20260812 06:19:30.449796 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000018 (ops 85-88)
I20260812 06:19:30.449836 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000019 (ops 89-93)
I20260812 06:19:30.449872 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000020 (ops 94-98)
I20260812 06:19:30.449914 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000021 (ops 99-103)
I20260812 06:19:30.449954 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000022 (ops 104-108)
I20260812 06:19:30.449992 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000023 (ops 109-112)
I20260812 06:19:30.450032 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000024 (ops 113-117)
I20260812 06:19:30.450073 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000025 (ops 118-122)
I20260812 06:19:30.450112 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000026 (ops 123-127)
I20260812 06:19:30.476508 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: LogGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:30.477142 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e): 493 bytes on disk
I20260812 06:19:30.477768 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.478331 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=5.165500
I20260812 06:19:30.501426 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.023s	user 0.017s	sys 0.004s Metrics: {"bytes_written":6769230,"delete_count":0,"lbm_write_time_us":9712,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:19:30.501932 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling LogGCOp(de1c83625ed04133b65ae7fdd282970e): free 12018000 bytes of WAL
I20260812 06:19:30.502173 30430 log_reader.cc:385] T de1c83625ed04133b65ae7fdd282970e: removed 1 log segments from log reader
I20260812 06:19:30.502233 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000027 (ops 128-132)
I20260812 06:19:30.505262 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: LogGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:30.505620 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:30.511641 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":1510,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:19:30.512158 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:30.735129 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.223s	user 0.136s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1080,"lbm_read_time_us":14733,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38008,"lbm_writes_lt_1ms":743,"mutex_wait_us":393,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":122,"threads_started":1,"update_count":3500}
I20260812 06:19:30.735960 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=16.079562
I20260812 06:19:30.789554 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.053s	user 0.029s	sys 0.021s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":23499,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:19:30.790051 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:30.805569 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":5232,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:30.806032 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:30.815932 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3649,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:30.816383 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:31.026096 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.210s	user 0.134s	sys 0.075s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877189,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":250,"lbm_read_time_us":13694,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34684,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:31.026626 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=15.087375
I20260812 06:19:31.082036 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.055s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":22662,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:31.082620 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.095922 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5192,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.096370 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:31.267495 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.171s	user 0.127s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":146,"lbm_read_time_us":12867,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28596,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:31.268201 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:31.325095 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.057s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20044,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.325711 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.338106 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.338619 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:31.525672 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.187s	user 0.147s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":12361,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33823,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:19:31.526407 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:31.593760 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.067s	user 0.033s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.594466 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.612586 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.613232 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:31.816370 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.203s	user 0.135s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":14246,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29944,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:31.816929 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=14.095187
I20260812 06:19:31.878909 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.062s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23149,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.879484 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.890218 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.890707 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushMRSOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:31.933956 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushMRSOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.043s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1528,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:31.934654 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling LogGCOp(de1c83625ed04133b65ae7fdd282970e): free 108535646 bytes of WAL
I20260812 06:19:31.934881 30430 log_reader.cc:385] T de1c83625ed04133b65ae7fdd282970e: removed 11 log segments from log reader
I20260812 06:19:31.934926 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000028 (ops 133-137)
I20260812 06:19:31.934957 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000029 (ops 138-142)
I20260812 06:19:31.935020 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000030 (ops 143-146)
I20260812 06:19:31.935052 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000031 (ops 147-151)
I20260812 06:19:31.935093 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000032 (ops 152-156)
I20260812 06:19:31.935148 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000033 (ops 157-160)
I20260812 06:19:31.935189 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000034 (ops 161-165)
I20260812 06:19:31.935228 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000035 (ops 166-170)
I20260812 06:19:31.935267 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000036 (ops 171-175)
I20260812 06:19:31.935310 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000037 (ops 176-180)
I20260812 06:19:31.935346 30430 log.cc:1079] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: Deleting log segment in path: /tmp/dist-test-taskUx_CYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561662961-30106-0/minicluster-data/ts-0-root/wals/de1c83625ed04133b65ae7fdd282970e/wal-000000038 (ops 181-185)
I20260812 06:19:31.958902 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: LogGCOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:31.959427 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.985453 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.985931 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e): 447 bytes on disk
I20260812 06:19:31.986351 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: UndoDeltaBlockGCOp(de1c83625ed04133b65ae7fdd282970e) 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:19:31.986886 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=2.188937
I20260812 06:19:31.997649 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.998448 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:32.240593 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.242s	user 0.149s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1538,"lbm_read_time_us":16524,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36949,"lbm_writes_lt_1ms":743,"mutex_wait_us":595,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21760,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:32.241266 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e): perf score=18.063937
I20260812 06:19:32.309721 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: FlushDeltaMemStoresOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.068s	user 0.040s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30131,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.310294 30495 maintenance_manager.cc:419] P 8a4969e7533b4f608677854073a95431: Scheduling MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e): perf score=1.000000
I20260812 06:19:32.324641 30106 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.943s	user 1.820s	sys 0.191s
I20260812 06:19:32.411250 30106 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.001s	sys 0.000s
I20260812 06:19:32.411765 30106 tablet_server.cc:179] TabletServer@127.29.102.129:0 shutting down...
I20260812 06:19:32.471990 30430 maintenance_manager.cc:643] P 8a4969e7533b4f608677854073a95431: MajorDeltaCompactionOp(de1c83625ed04133b65ae7fdd282970e) complete. Timing: real 0.162s	user 0.101s	sys 0.060s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1428,"lbm_read_time_us":14472,"lbm_reads_lt_1ms":559,"lbm_write_time_us":24918,"lbm_writes_lt_1ms":543,"mutex_wait_us":397,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:19:32.472606 30106 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:32.472862 30106 tablet_replica.cc:333] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431: stopping tablet replica
I20260812 06:19:32.473001 30106 raft_consensus.cc:2243] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.473177 30106 raft_consensus.cc:2272] T de1c83625ed04133b65ae7fdd282970e P 8a4969e7533b4f608677854073a95431 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.478348 30106 tablet_server.cc:196] TabletServer@127.29.102.129:0 shutdown complete.
I20260812 06:19:32.517477 30106 master.cc:562] Master@127.29.102.190:33011 shutting down...
I20260812 06:19:32.520941 30106 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.521126 30106 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.521178 30106 tablet_replica.cc:333] T 00000000000000000000000000000000 P bda4ed1950bd4cc3b88a31e36e21ef01: stopping tablet replica
I20260812 06:19:32.533882 30106 master.cc:584] Master@127.29.102.190:33011 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5456 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10957 ms total)

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