[==========] 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:18:16.375787  1042 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.4.190:35693
I20260812 06:18:16.376840  1042 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:18:16.377456  1042 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.383725  1054 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:18:16.383824  1052 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:18:16.383919  1042 server_base.cc:1061] running on GCE node
W20260812 06:18:16.384114  1051 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:18:16.384632  1042 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.384770  1042 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:18:16.384840  1042 hybrid_clock.cc:648] HybridClock initialized: now 1786515496384837 us; error 0 us; skew 500 ppm
I20260812 06:18:16.386641  1042 webserver.cc:533] Webserver started at http://127.1.4.190:40937/ using document root <none> and password file <none>
I20260812 06:18:16.387259  1042 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.387349  1042 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.387590  1042 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.389266  1042 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/master-0-root/instance:
uuid: "df2c4734d99e4610914c6fe83c6353b8"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-n326"
I20260812 06:18:16.392894  1042 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:16.395153  1063 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:18:16.396334  1042 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:16.396494  1042 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/master-0-root
uuid: "df2c4734d99e4610914c6fe83c6353b8"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-n326"
I20260812 06:18:16.396626  1042 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-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:18:16.410377  1042 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.411238  1042 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:18:16.411461  1042 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.420437  1155 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.4.190:35693 every 8 connection(s)
I20260812 06:18:16.420447  1042 rpc_server.cc:307] RPC server started. Bound to: 127.1.4.190:35693
I20260812 06:18:16.423135  1156 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:18:16.428800  1156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: Bootstrap starting.
I20260812 06:18:16.431269  1156 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.432201  1156 log.cc:826] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:16.434103  1156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: No bootstrap required, opened a new log
I20260812 06:18:16.437064  1156 raft_consensus.cc:359] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER }
I20260812 06:18:16.437238  1156 raft_consensus.cc:385] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.437281  1156 raft_consensus.cc:740] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: df2c4734d99e4610914c6fe83c6353b8, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.437827  1156 consensus_queue.cc:260] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [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: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER }
I20260812 06:18:16.437959  1156 raft_consensus.cc:399] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.437999  1156 raft_consensus.cc:493] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.438091  1156 raft_consensus.cc:3060] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.438874  1156 raft_consensus.cc:515] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER }
I20260812 06:18:16.439339  1156 leader_election.cc:304] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [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: df2c4734d99e4610914c6fe83c6353b8; no voters: 
I20260812 06:18:16.439672  1156 leader_election.cc:290] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.439849  1161 raft_consensus.cc:2804] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.440142  1161 raft_consensus.cc:697] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 1 LEADER]: Becoming Leader. State: Replica: df2c4734d99e4610914c6fe83c6353b8, State: Running, Role: LEADER
I20260812 06:18:16.440608  1161 consensus_queue.cc:237] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [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: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER }
I20260812 06:18:16.440716  1156 sys_catalog.cc:565] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:16.442737  1163 sys_catalog.cc:455] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader df2c4734d99e4610914c6fe83c6353b8. Latest consensus state: current_term: 1 leader_uuid: "df2c4734d99e4610914c6fe83c6353b8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER } }
I20260812 06:18:16.442871  1163 sys_catalog.cc:458] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.443167  1162 sys_catalog.cc:455] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "df2c4734d99e4610914c6fe83c6353b8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df2c4734d99e4610914c6fe83c6353b8" member_type: VOTER } }
I20260812 06:18:16.443221  1042 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:16.443252  1162 sys_catalog.cc:458] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.443276  1185 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:16.445734  1185 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:16.450719  1185 catalog_manager.cc:1383] Generated new cluster ID: d1f1a550295145c0bb0e78435bf1892e
I20260812 06:18:16.450860  1185 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:16.468875  1185 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:16.469803  1185 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:16.477928  1185 catalog_manager.cc:6092] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: Generated new TSK 0
I20260812 06:18:16.478590  1185 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:16.508260  1042 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.511411  1194 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:18:16.511502  1197 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:18:16.511631  1200 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:18:16.511786  1042 server_base.cc:1061] running on GCE node
I20260812 06:18:16.512101  1042 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.512153  1042 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:18:16.512171  1042 hybrid_clock.cc:648] HybridClock initialized: now 1786515496512172 us; error 0 us; skew 500 ppm
I20260812 06:18:16.513536  1042 webserver.cc:533] Webserver started at http://127.1.4.129:40387/ using document root <none> and password file <none>
I20260812 06:18:16.513736  1042 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.513800  1042 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.513911  1042 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.514328  1042 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/instance:
uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-n326"
I20260812 06:18:16.516038  1042 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:16.517136  1209 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:18:16.517395  1042 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:16.517472  1042 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root
uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-n326"
I20260812 06:18:16.517567  1042 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-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:18:16.535570  1042 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.536489  1042 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.537072  1042 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:16.538005  1042 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:16.538061  1042 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.538136  1042 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:16.538187  1042 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.545297  1042 rpc_server.cc:307] RPC server started. Bound to: 127.1.4.129:36057
I20260812 06:18:16.545401  1309 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.4.129:36057 every 8 connection(s)
I20260812 06:18:16.561021  1310 heartbeater.cc:344] Connected to a master server at 127.1.4.190:35693
I20260812 06:18:16.561318  1310 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:16.561867  1310 heartbeater.cc:507] Master 127.1.4.190:35693 requested a full tablet report, sending...
I20260812 06:18:16.563438  1099 ts_manager.cc:194] Registered new tserver with Master: 2c5e0ae2fbfd4568bb278e0b699fef7f (127.1.4.129:36057)
I20260812 06:18:16.563959  1042 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017941676s
I20260812 06:18:16.565102  1099 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51720
I20260812 06:18:16.574891  1099 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51730:
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:18:16.590591  1251 tablet_service.cc:1511] Processing CreateTablet for tablet c7d0817cea854a099c6321c09b67606e (DEFAULT_TABLE table=heavy-update-compaction-test [id=ab9faf8220124b8199dc24eb56466f7e]), partition=
I20260812 06:18:16.591193  1251 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c7d0817cea854a099c6321c09b67606e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:16.593586  1331 tablet_bootstrap.cc:492] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Bootstrap starting.
I20260812 06:18:16.595059  1331 tablet_bootstrap.cc:654] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.596392  1331 tablet_bootstrap.cc:492] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: No bootstrap required, opened a new log
I20260812 06:18:16.596483  1331 ts_tablet_manager.cc:1403] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:16.596988  1331 raft_consensus.cc:359] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36057 } }
I20260812 06:18:16.597096  1331 raft_consensus.cc:385] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.597122  1331 raft_consensus.cc:740] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2c5e0ae2fbfd4568bb278e0b699fef7f, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.597283  1331 consensus_queue.cc:260] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [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: "2c5e0ae2fbfd4568bb278e0b699fef7f" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36057 } }
I20260812 06:18:16.597360  1331 raft_consensus.cc:399] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.597436  1331 raft_consensus.cc:493] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.597527  1331 raft_consensus.cc:3060] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.598606  1331 raft_consensus.cc:515] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36057 } }
I20260812 06:18:16.598732  1331 leader_election.cc:304] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [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: 2c5e0ae2fbfd4568bb278e0b699fef7f; no voters: 
I20260812 06:18:16.599025  1331 leader_election.cc:290] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.599180  1336 raft_consensus.cc:2804] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.599428  1336 raft_consensus.cc:697] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 1 LEADER]: Becoming Leader. State: Replica: 2c5e0ae2fbfd4568bb278e0b699fef7f, State: Running, Role: LEADER
I20260812 06:18:16.599471  1331 ts_tablet_manager.cc:1434] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:16.599654  1336 consensus_queue.cc:237] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [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: "2c5e0ae2fbfd4568bb278e0b699fef7f" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36057 } }
I20260812 06:18:16.599838  1310 heartbeater.cc:499] Master 127.1.4.190:35693 was elected leader, sending a full tablet report...
I20260812 06:18:16.602583  1099 catalog_manager.cc:5719] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f reported cstate change: term changed from 0 to 1, leader changed from <none> to 2c5e0ae2fbfd4568bb278e0b699fef7f (127.1.4.129). New cstate: current_term: 1 leader_uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c5e0ae2fbfd4568bb278e0b699fef7f" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36057 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:16.674324  1042 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.020s	sys 0.009s
I20260812 06:18:16.796805  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushMRSOp(c7d0817cea854a099c6321c09b67606e): perf score=15.086190
I20260812 06:18:16.924660  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushMRSOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.127s	user 0.093s	sys 0.032s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":334,"delete_count":0,"dirs.queue_time_us":30,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":862,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":29487,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":204,"threads_started":1,"update_count":1050}
I20260812 06:18:16.925637  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 11976772 bytes of WAL
I20260812 06:18:16.925932  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 1 log segments from log reader
I20260812 06:18:16.926019  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000001 (ops 1-6)
I20260812 06:18:16.928723  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:16.929036  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:16.942027  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4851,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:16.942523  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:17.084529  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.142s	user 0.113s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":479,"lbm_read_time_us":9247,"lbm_reads_lt_1ms":364,"lbm_write_time_us":23321,"lbm_writes_lt_1ms":343,"mutex_wait_us":22,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":309,"threads_started":5,"update_count":1500}
I20260812 06:18:17.085106  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=6.157687
I20260812 06:18:17.119748  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.034s	user 0.009s	sys 0.019s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12880,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:17.120271  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:17.221581  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.101s	user 0.073s	sys 0.028s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12426369,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":243,"lbm_read_time_us":5442,"lbm_reads_lt_1ms":263,"lbm_write_time_us":18842,"lbm_writes_lt_1ms":243,"mutex_wait_us":29,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":1000}
I20260812 06:18:17.222206  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e): 12308958 bytes on disk
I20260812 06:18:17.222739  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.223266  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=6.157687
I20260812 06:18:17.252221  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11888,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:17.252671  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:17.340875  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.088s	user 0.053s	sys 0.024s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12426369,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":2321,"lbm_read_time_us":4860,"lbm_reads_lt_1ms":263,"lbm_write_time_us":13058,"lbm_writes_lt_1ms":243,"mutex_wait_us":962,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":1000}
I20260812 06:18:17.341902  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=6.157687
I20260812 06:18:17.387216  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.045s	user 0.027s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":17370,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:18:17.387838  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:17.413868  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.026s	user 0.012s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.414688  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:17.592942  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.178s	user 0.121s	sys 0.054s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528899,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":13314,"lbm_reads_lt_1ms":364,"lbm_write_time_us":26871,"lbm_writes_lt_1ms":343,"mutex_wait_us":490,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":1500}
I20260812 06:18:17.593619  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:17.640403  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.047s	user 0.019s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20896,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.640937  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:17.651747  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.652248  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:17.830727  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.177s	user 0.115s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":12682,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28422,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:17.831600  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:17.886307  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.055s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21823,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.886888  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:17.898422  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.898900  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:18.063927  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.165s	user 0.111s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":11118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29899,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:18:18.064770  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:18.119346  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.054s	user 0.015s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22874,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.119973  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:18.275844  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.156s	user 0.082s	sys 0.067s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":660,"lbm_read_time_us":9776,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26191,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:18:18.276578  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:18.325733  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.049s	user 0.012s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19662,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.326280  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:18.337764  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4300,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.338351  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushMRSOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:18.372210  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushMRSOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1330,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1470,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:18.372993  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 120553366 bytes of WAL
I20260812 06:18:18.373222  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 12 log segments from log reader
I20260812 06:18:18.373267  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000002 (ops 7-11)
I20260812 06:18:18.373296  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000003 (ops 12-16)
I20260812 06:18:18.373360  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000004 (ops 17-21)
I20260812 06:18:18.373389  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000005 (ops 22-26)
I20260812 06:18:18.373432  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000006 (ops 27-30)
I20260812 06:18:18.373471  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000007 (ops 31-35)
I20260812 06:18:18.373507  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000008 (ops 36-40)
I20260812 06:18:18.373546  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000009 (ops 41-45)
I20260812 06:18:18.373584  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000010 (ops 46-50)
I20260812 06:18:18.373622  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000011 (ops 51-55)
I20260812 06:18:18.373659  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000012 (ops 56-60)
I20260812 06:18:18.373697  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000013 (ops 61-64)
I20260812 06:18:18.404515  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:18.404934  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e): 462 bytes on disk
I20260812 06:18:18.405475  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.406030  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=3.181125
I20260812 06:18:18.422678  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4802,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:18.423187  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:18.432987  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3806,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.433487  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:18.675408  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.242s	user 0.139s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938774,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":972,"lbm_read_time_us":16545,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41996,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:18.676087  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=18.063937
I20260812 06:18:18.728288  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.052s	user 0.018s	sys 0.033s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":24576,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:18.728760  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:18.916635  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.188s	user 0.124s	sys 0.049s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733605,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":136,"dirs.run_cpu_time_us":863,"dirs.run_wall_time_us":5330,"lbm_read_time_us":13784,"lbm_reads_lt_1ms":567,"lbm_write_time_us":27879,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:18:18.917339  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:18.988651  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.071s	user 0.032s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25090,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.989146  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:18.999756  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.000171  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:19.188197  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.188s	user 0.128s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":14113,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32513,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:19.189174  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=11.118625
I20260812 06:18:19.229761  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.040s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17636,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.230549  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:19.244953  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5235,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.245534  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:19.407518  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.162s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":616,"lbm_read_time_us":8614,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24298,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.408244  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:19.456562  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.046s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.457163  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:19.468578  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.469069  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:19.631042  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.162s	user 0.113s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":10580,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31216,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:18:19.631664  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:19.683391  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.052s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21200,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.683905  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:19.699616  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5818,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.700099  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:19.858464  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.158s	user 0.098s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":668,"lbm_read_time_us":12122,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29697,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:19.859180  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=11.118625
I20260812 06:18:19.904304  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.045s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":19677,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.905045  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:19.924474  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.019s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5944,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.925034  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushMRSOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:19.980762  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushMRSOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.056s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1388,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1695,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:19.981627  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 121006383 bytes of WAL
I20260812 06:18:19.981912  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 12 log segments from log reader
I20260812 06:18:19.981962  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000014 (ops 65-69)
I20260812 06:18:19.981997  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000015 (ops 70-74)
I20260812 06:18:19.982046  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000016 (ops 75-79)
I20260812 06:18:19.982095  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000017 (ops 80-84)
I20260812 06:18:19.982138  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000018 (ops 85-89)
I20260812 06:18:19.982184  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000019 (ops 90-94)
I20260812 06:18:19.982206  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000020 (ops 95-99)
I20260812 06:18:19.982266  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000021 (ops 100-104)
I20260812 06:18:19.982309  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000022 (ops 105-108)
I20260812 06:18:19.982354  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000023 (ops 109-113)
I20260812 06:18:19.982398  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000024 (ops 114-118)
I20260812 06:18:19.982431  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000025 (ops 119-123)
I20260812 06:18:20.012270  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:20.012708  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e): 483 bytes on disk
I20260812 06:18:20.013278  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.013779  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=6.157687
I20260812 06:18:20.042502  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.029s	user 0.019s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12672,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:20.043138  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 8767174 bytes of WAL
I20260812 06:18:20.043346  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 1 log segments from log reader
I20260812 06:18:20.043390  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000026 (ops 124-128)
I20260812 06:18:20.045285  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:20.045594  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:20.057838  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.012s	user 0.007s	sys 0.003s 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:18:20.058287  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:20.295922  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.237s	user 0.166s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938781,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":680,"lbm_read_time_us":18216,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40425,"lbm_writes_lt_1ms":743,"mutex_wait_us":66,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:20.296474  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=18.063937
I20260812 06:18:20.362479  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.066s	user 0.041s	sys 0.020s Metrics: {"bytes_written":20512311,"delete_count":0,"lbm_write_time_us":29119,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.363343  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=3.181125
I20260812 06:18:20.378583  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5010,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:20.379114  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:20.389333  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.389817  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:20.574386  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.184s	user 0.136s	sys 0.048s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":151,"lbm_read_time_us":15695,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38719,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3500}
I20260812 06:18:20.575275  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:20.617425  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.618314  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:20.635295  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4672,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.636039  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:20.814033  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.178s	user 0.127s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":9928,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35198,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":2500}
I20260812 06:18:20.814702  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:20.872632  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.058s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26364,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.873142  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:21.021140  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.148s	user 0.106s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":249,"lbm_read_time_us":12753,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23179,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.021925  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:21.074438  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.052s	user 0.016s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19027,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.074990  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:21.091475  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.016s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.092133  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:21.285573  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.193s	user 0.110s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":11458,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30797,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:21.286113  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=14.095187
I20260812 06:18:21.349990  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.064s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.350497  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:21.362326  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.362836  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushMRSOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:21.393185  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushMRSOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.030s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1252,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2109,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:21.393859  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 111786491 bytes of WAL
I20260812 06:18:21.394104  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 11 log segments from log reader
I20260812 06:18:21.394172  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000027 (ops 129-132)
I20260812 06:18:21.394229  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000028 (ops 133-137)
I20260812 06:18:21.394286  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000029 (ops 138-142)
I20260812 06:18:21.394330  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000030 (ops 143-147)
I20260812 06:18:21.394372  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000031 (ops 148-152)
I20260812 06:18:21.394410  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000032 (ops 153-156)
I20260812 06:18:21.394448  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000033 (ops 157-161)
I20260812 06:18:21.394487  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000034 (ops 162-166)
I20260812 06:18:21.394527  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000035 (ops 167-171)
I20260812 06:18:21.394564  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000036 (ops 172-176)
I20260812 06:18:21.394606  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000037 (ops 177-181)
I20260812 06:18:21.422032  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:21.428248  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:21.451921  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.023s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.452440  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling LogGCOp(c7d0817cea854a099c6321c09b67606e): free 12017954 bytes of WAL
I20260812 06:18:21.452666  1219 log_reader.cc:385] T c7d0817cea854a099c6321c09b67606e: removed 1 log segments from log reader
I20260812 06:18:21.452709  1219 log.cc:1079] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/c7d0817cea854a099c6321c09b67606e/wal-000000038 (ops 182-186)
I20260812 06:18:21.455227  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: LogGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:21.455562  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=2.188937
I20260812 06:18:21.466634  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.011s	user 0.007s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.467468  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e): 447 bytes on disk
I20260812 06:18:21.468178  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: UndoDeltaBlockGCOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":139,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.468734  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:21.708804  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.240s	user 0.144s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938784,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":564,"lbm_read_time_us":19204,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36725,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:21.709540  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e): perf score=18.063937
I20260812 06:18:21.772867  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: FlushDeltaMemStoresOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.063s	user 0.037s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28521,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:21.773667  1311 maintenance_manager.cc:419] P 2c5e0ae2fbfd4568bb278e0b699fef7f: Scheduling MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e): perf score=1.000000
I20260812 06:18:21.854976  1042 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.181s	user 1.894s	sys 0.151s
I20260812 06:18:21.915043  1042 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.000s	sys 0.001s
I20260812 06:18:21.915768  1042 tablet_server.cc:179] TabletServer@127.1.4.129:0 shutting down...
I20260812 06:18:21.938220  1219 maintenance_manager.cc:643] P 2c5e0ae2fbfd4568bb278e0b699fef7f: MajorDeltaCompactionOp(c7d0817cea854a099c6321c09b67606e) complete. Timing: real 0.164s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733606,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":288,"lbm_read_time_us":14349,"lbm_reads_lt_1ms":559,"lbm_write_time_us":26102,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:18:21.938912  1042 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:21.939428  1042 tablet_replica.cc:333] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f: stopping tablet replica
I20260812 06:18:21.939666  1042 raft_consensus.cc:2243] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.939896  1042 raft_consensus.cc:2272] T c7d0817cea854a099c6321c09b67606e P 2c5e0ae2fbfd4568bb278e0b699fef7f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.956596  1042 tablet_server.cc:196] TabletServer@127.1.4.129:0 shutdown complete.
I20260812 06:18:21.991356  1042 master.cc:562] Master@127.1.4.190:35693 shutting down...
I20260812 06:18:21.995904  1042 raft_consensus.cc:2243] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.996134  1042 raft_consensus.cc:2272] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.996248  1042 tablet_replica.cc:333] T 00000000000000000000000000000000 P df2c4734d99e4610914c6fe83c6353b8: stopping tablet replica
I20260812 06:18:22.010093  1042 master.cc:584] Master@127.1.4.190:35693 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5739 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:22.128684  1042 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.4.190:33553
I20260812 06:18:22.129256  1042 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.131871  1361 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:18:22.131963  1042 server_base.cc:1061] running on GCE node
W20260812 06:18:22.131922  1368 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:18:22.131930  1359 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:18:22.132362  1042 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.132412  1042 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:18:22.132428  1042 hybrid_clock.cc:648] HybridClock initialized: now 1786515502132428 us; error 0 us; skew 500 ppm
I20260812 06:18:22.133340  1042 webserver.cc:533] Webserver started at http://127.1.4.190:41245/ using document root <none> and password file <none>
I20260812 06:18:22.133541  1042 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.133611  1042 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.133699  1042 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.134120  1042 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/master-0-root/instance:
uuid: "70dfe3b1d02a45999cf03f5e4f7512ab"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-n326"
I20260812 06:18:22.135787  1042 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:22.136700  1374 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:18:22.136960  1042 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:22.137028  1042 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/master-0-root
uuid: "70dfe3b1d02a45999cf03f5e4f7512ab"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-n326"
I20260812 06:18:22.137122  1042 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-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:18:22.144874  1042 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.145239  1042 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.150594  1042 rpc_server.cc:307] RPC server started. Bound to: 127.1.4.190:33553
I20260812 06:18:22.153167  1461 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.4.190:33553 every 8 connection(s)
I20260812 06:18:22.156209  1462 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:18:22.157997  1462 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab: Bootstrap starting.
I20260812 06:18:22.158748  1462 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.159822  1462 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab: No bootstrap required, opened a new log
I20260812 06:18:22.160158  1462 raft_consensus.cc:359] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER }
I20260812 06:18:22.160243  1462 raft_consensus.cc:385] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.160264  1462 raft_consensus.cc:740] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 70dfe3b1d02a45999cf03f5e4f7512ab, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.160363  1462 consensus_queue.cc:260] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [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: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER }
I20260812 06:18:22.160420  1462 raft_consensus.cc:399] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.160442  1462 raft_consensus.cc:493] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.160506  1462 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.161125  1462 raft_consensus.cc:515] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER }
I20260812 06:18:22.161235  1462 leader_election.cc:304] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [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: 70dfe3b1d02a45999cf03f5e4f7512ab; no voters: 
I20260812 06:18:22.161387  1462 leader_election.cc:290] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.161543  1466 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.161728  1466 raft_consensus.cc:697] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 1 LEADER]: Becoming Leader. State: Replica: 70dfe3b1d02a45999cf03f5e4f7512ab, State: Running, Role: LEADER
I20260812 06:18:22.161881  1462 sys_catalog.cc:565] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:22.161888  1466 consensus_queue.cc:237] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [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: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER }
I20260812 06:18:22.162395  1468 sys_catalog.cc:455] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER } }
I20260812 06:18:22.162422  1469 sys_catalog.cc:455] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [sys.catalog]: SysCatalogTable state changed. Reason: New leader 70dfe3b1d02a45999cf03f5e4f7512ab. Latest consensus state: current_term: 1 leader_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70dfe3b1d02a45999cf03f5e4f7512ab" member_type: VOTER } }
I20260812 06:18:22.162560  1468 sys_catalog.cc:458] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.162647  1469 sys_catalog.cc:458] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.163257  1482 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:22.164192  1482 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:22.164381  1042 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:22.165977  1482 catalog_manager.cc:1383] Generated new cluster ID: 9801033a736749e6bd582def1e63b797
I20260812 06:18:22.166036  1482 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:22.177205  1482 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:22.177783  1482 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:22.184247  1482 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab: Generated new TSK 0
I20260812 06:18:22.184424  1482 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:22.196779  1042 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.198841  1506 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:18:22.198956  1499 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:18:22.199013  1042 server_base.cc:1061] running on GCE node
W20260812 06:18:22.199002  1498 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:18:22.199399  1042 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.199452  1042 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:18:22.199470  1042 hybrid_clock.cc:648] HybridClock initialized: now 1786515502199471 us; error 0 us; skew 500 ppm
I20260812 06:18:22.200582  1042 webserver.cc:533] Webserver started at http://127.1.4.129:35825/ using document root <none> and password file <none>
I20260812 06:18:22.200765  1042 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.200855  1042 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.200958  1042 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.201395  1042 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/instance:
uuid: "db0d5fc05f6147f080f8c1c5a5f211ad"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-n326"
I20260812 06:18:22.203184  1042 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:22.204519  1515 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:18:22.204793  1042 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:22.204900  1042 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root
uuid: "db0d5fc05f6147f080f8c1c5a5f211ad"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-n326"
I20260812 06:18:22.204994  1042 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-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:18:22.226313  1042 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.226727  1042 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.227119  1042 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:22.227617  1042 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:22.227679  1042 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.227741  1042 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:22.227775  1042 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.232141  1042 rpc_server.cc:307] RPC server started. Bound to: 127.1.4.129:36361
I20260812 06:18:22.232671  1621 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.4.129:36361 every 8 connection(s)
I20260812 06:18:22.243352  1624 heartbeater.cc:344] Connected to a master server at 127.1.4.190:33553
I20260812 06:18:22.243461  1624 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:22.243747  1624 heartbeater.cc:507] Master 127.1.4.190:33553 requested a full tablet report, sending...
I20260812 06:18:22.244410  1404 ts_manager.cc:194] Registered new tserver with Master: db0d5fc05f6147f080f8c1c5a5f211ad (127.1.4.129:36361)
I20260812 06:18:22.245029  1042 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0121891s
I20260812 06:18:22.245283  1404 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58132
I20260812 06:18:22.252017  1404 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58142:
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:18:22.261484  1564 tablet_service.cc:1511] Processing CreateTablet for tablet 5a73a6ba95804dc28bdf95890f6cbbb2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=10bbfb9f503b4a599e0d06d203f92dc3]), partition=
I20260812 06:18:22.261724  1564 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5a73a6ba95804dc28bdf95890f6cbbb2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:22.263861  1644 tablet_bootstrap.cc:492] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Bootstrap starting.
I20260812 06:18:22.264828  1644 tablet_bootstrap.cc:654] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.266093  1644 tablet_bootstrap.cc:492] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: No bootstrap required, opened a new log
I20260812 06:18:22.266207  1644 ts_tablet_manager.cc:1403] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:22.266701  1644 raft_consensus.cc:359] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db0d5fc05f6147f080f8c1c5a5f211ad" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36361 } }
I20260812 06:18:22.266822  1644 raft_consensus.cc:385] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.266878  1644 raft_consensus.cc:740] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: db0d5fc05f6147f080f8c1c5a5f211ad, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.267045  1644 consensus_queue.cc:260] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [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: "db0d5fc05f6147f080f8c1c5a5f211ad" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36361 } }
I20260812 06:18:22.267215  1644 raft_consensus.cc:399] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.267273  1644 raft_consensus.cc:493] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.267339  1644 raft_consensus.cc:3060] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.268121  1644 raft_consensus.cc:515] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db0d5fc05f6147f080f8c1c5a5f211ad" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36361 } }
I20260812 06:18:22.268289  1644 leader_election.cc:304] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [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: db0d5fc05f6147f080f8c1c5a5f211ad; no voters: 
I20260812 06:18:22.268527  1644 leader_election.cc:290] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.268698  1649 raft_consensus.cc:2804] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.268956  1624 heartbeater.cc:499] Master 127.1.4.190:33553 was elected leader, sending a full tablet report...
I20260812 06:18:22.268968  1649 raft_consensus.cc:697] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 1 LEADER]: Becoming Leader. State: Replica: db0d5fc05f6147f080f8c1c5a5f211ad, State: Running, Role: LEADER
I20260812 06:18:22.268970  1644 ts_tablet_manager.cc:1434] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:22.269157  1649 consensus_queue.cc:237] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [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: "db0d5fc05f6147f080f8c1c5a5f211ad" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36361 } }
I20260812 06:18:22.270640  1404 catalog_manager.cc:5719] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad reported cstate change: term changed from 0 to 1, leader changed from <none> to db0d5fc05f6147f080f8c1c5a5f211ad (127.1.4.129). New cstate: current_term: 1 leader_uuid: "db0d5fc05f6147f080f8c1c5a5f211ad" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db0d5fc05f6147f080f8c1c5a5f211ad" member_type: VOTER last_known_addr { host: "127.1.4.129" port: 36361 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:22.332974  1042 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.004s
I20260812 06:18:22.483335  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=19.054940
I20260812 06:18:22.642135  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.158s	user 0.100s	sys 0.056s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":839,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40001,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:18:22.642956  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): free 20743880 bytes of WAL
I20260812 06:18:22.643298  1523 log_reader.cc:385] T 5a73a6ba95804dc28bdf95890f6cbbb2: removed 2 log segments from log reader
I20260812 06:18:22.643392  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000001 (ops 1-6)
I20260812 06:18:22.643455  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000002 (ops 7-11)
I20260812 06:18:22.650388  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:22.650815  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): 16411395 bytes on disk
I20260812 06:18:22.651490  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.651945  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:22.667338  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.667805  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:22.841439  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.173s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":570,"lbm_read_time_us":10890,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27750,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":343,"threads_started":5,"update_count":2000}
I20260812 06:18:22.842039  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:22.896739  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.054s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20964,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.897190  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:22.927603  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.030s	user 0.007s	sys 0.023s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.928395  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:23.126138  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.197s	user 0.129s	sys 0.068s 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":400,"lbm_read_time_us":14786,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31495,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:23.126713  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:23.177498  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.178004  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:23.197194  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.019s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.197947  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:23.389237  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.191s	user 0.147s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":11431,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28458,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:23.389806  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:23.454850  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.065s	user 0.039s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":38924,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.455471  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:23.471771  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.472304  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:23.637956  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.165s	user 0.125s	sys 0.040s 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":626,"lbm_read_time_us":11308,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34142,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:18:23.638617  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=10.126437
I20260812 06:18:23.671965  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.033s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14589,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:23.672472  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:23.684926  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.685705  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:23.817189  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.131s	user 0.103s	sys 0.028s 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":1379,"lbm_read_time_us":8369,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25988,"lbm_writes_lt_1ms":443,"mutex_wait_us":488,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:23.818038  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=10.126437
I20260812 06:18:23.855803  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16254,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:23.856608  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:23.869292  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.869892  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:23.990396  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.120s	user 0.092s	sys 0.028s 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":1233,"lbm_read_time_us":7813,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22637,"lbm_writes_lt_1ms":443,"mutex_wait_us":353,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:18:23.991050  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=10.126437
I20260812 06:18:24.039880  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.049s	user 0.019s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15657,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.040539  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:24.051606  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.052083  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:24.095177  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.043s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1532,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1554,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:24.095773  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): free 124710294 bytes of WAL
I20260812 06:18:24.095991  1523 log_reader.cc:385] T 5a73a6ba95804dc28bdf95890f6cbbb2: removed 12 log segments from log reader
I20260812 06:18:24.096037  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000003 (ops 12-16)
I20260812 06:18:24.096065  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000004 (ops 17-21)
I20260812 06:18:24.096123  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000005 (ops 22-26)
I20260812 06:18:24.096168  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000006 (ops 27-31)
I20260812 06:18:24.096225  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000007 (ops 32-36)
I20260812 06:18:24.096266  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000008 (ops 37-41)
I20260812 06:18:24.096306  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000009 (ops 42-46)
I20260812 06:18:24.096345  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000010 (ops 47-51)
I20260812 06:18:24.096382  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000011 (ops 52-56)
I20260812 06:18:24.096424  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000012 (ops 57-61)
I20260812 06:18:24.096467  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000013 (ops 62-66)
I20260812 06:18:24.096504  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000014 (ops 67-71)
I20260812 06:18:24.125949  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:24.126394  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): 483 bytes on disk
I20260812 06:18:24.126814  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) 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:18:24.127326  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=3.181125
I20260812 06:18:24.141196  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.014s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:24.141626  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:24.151506  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.151894  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:24.357303  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.205s	user 0.129s	sys 0.071s 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":2806,"dirs.run_cpu_time_us":661,"dirs.run_wall_time_us":3396,"lbm_read_time_us":15144,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34354,"lbm_writes_lt_1ms":643,"mutex_wait_us":2043,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:18:24.358142  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=15.087375
I20260812 06:18:24.407548  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.049s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22214,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:24.408277  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:24.424647  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.016s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4614,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.425149  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:24.602908  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.178s	user 0.092s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":544,"lbm_read_time_us":13779,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32284,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:18:24.603578  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:24.664386  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.061s	user 0.028s	sys 0.030s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":21200,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.664937  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:24.675880  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.676332  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:24.865988  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.189s	user 0.134s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1274,"lbm_read_time_us":14880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30066,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:24.866496  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:24.945971  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.079s	user 0.031s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28274,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.946521  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:24.957388  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.957893  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:25.170012  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.212s	user 0.132s	sys 0.071s 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":239,"lbm_read_time_us":13833,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34069,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:18:25.170634  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:25.240191  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.069s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21656,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.241040  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:25.263765  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.022s	user 0.011s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.264482  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:25.445852  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.181s	user 0.122s	sys 0.056s 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":371,"lbm_read_time_us":13461,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29135,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:18:25.446372  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:25.503568  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.057s	user 0.034s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23950,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.504089  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:25.519742  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.015s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.520228  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:25.703922  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.183s	user 0.116s	sys 0.060s 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":514,"lbm_read_time_us":11433,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30057,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:25.704622  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:25.758798  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.054s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.759374  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:25.771993  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.772951  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:25.805886  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1810,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:25.806542  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): free 133024342 bytes of WAL
I20260812 06:18:25.806769  1523 log_reader.cc:385] T 5a73a6ba95804dc28bdf95890f6cbbb2: removed 13 log segments from log reader
I20260812 06:18:25.806813  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000015 (ops 72-76)
I20260812 06:18:25.806869  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000016 (ops 77-81)
I20260812 06:18:25.806914  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000017 (ops 82-86)
I20260812 06:18:25.806943  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000018 (ops 87-90)
I20260812 06:18:25.806984  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000019 (ops 91-95)
I20260812 06:18:25.807024  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000020 (ops 96-100)
I20260812 06:18:25.807089  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000021 (ops 101-105)
I20260812 06:18:25.807133  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000022 (ops 106-110)
I20260812 06:18:25.807175  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000023 (ops 111-115)
I20260812 06:18:25.807215  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000024 (ops 116-120)
I20260812 06:18:25.807255  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000025 (ops 121-125)
I20260812 06:18:25.807293  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000026 (ops 126-130)
I20260812 06:18:25.807333  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000027 (ops 131-135)
I20260812 06:18:25.841575  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.035s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:18:25.842089  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=4.173312
I20260812 06:18:25.867513  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.025s	user 0.025s	sys 0.000s Metrics: {"bytes_written":6235918,"delete_count":0,"lbm_write_time_us":10500,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:18:25.868079  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:25.874492  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":2113,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:18:25.874962  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): 492 bytes on disk
I20260812 06:18:25.875411  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.875948  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:26.104547  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.228s	user 0.135s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979697,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":384,"lbm_read_time_us":14819,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41386,"lbm_writes_lt_1ms":743,"mutex_wait_us":31,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:18:26.105113  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=15.087375
I20260812 06:18:26.160916  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.056s	user 0.053s	sys 0.000s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24702,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:26.161551  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:26.178740  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.017s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4963,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.179307  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:26.365391  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.186s	user 0.122s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":14507,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31227,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:26.366039  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:26.429272  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.063s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20871,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.429903  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:26.440867  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.441303  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:26.630762  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.189s	user 0.113s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":14582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29802,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:18:26.631417  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:26.691330  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.060s	user 0.027s	sys 0.032s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22139,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.691960  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:26.702986  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.703552  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:26.888777  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.185s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":13362,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32578,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":73088,"update_count":2500}
I20260812 06:18:26.889537  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=11.118625
I20260812 06:18:26.925786  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.036s	user 0.010s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15252,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:26.926470  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:26.953951  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.027s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5543,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.954411  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:26.964818  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.965298  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:27.148681  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.183s	user 0.108s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1008,"lbm_read_time_us":10671,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28979,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:27.149289  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=14.095187
I20260812 06:18:27.202971  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.053s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25544,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.203543  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:27.214164  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.215055  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:27.375806  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.161s	user 0.110s	sys 0.045s 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":696,"lbm_read_time_us":11380,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30309,"lbm_writes_lt_1ms":543,"mutex_wait_us":357,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:18:27.376560  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=11.118625
I20260812 06:18:27.415740  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.039s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16984,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.416834  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:27.432498  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.433120  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:27.476490  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushMRSOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.043s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1827,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:27.477475  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=3.181125
I20260812 06:18:27.494761  1042 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.162s	user 1.931s	sys 0.187s
I20260812 06:18:27.496526  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.019s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6931,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:27.497215  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): free 133024654 bytes of WAL
I20260812 06:18:27.497490  1523 log_reader.cc:385] T 5a73a6ba95804dc28bdf95890f6cbbb2: removed 13 log segments from log reader
I20260812 06:18:27.497552  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000028 (ops 136-140)
I20260812 06:18:27.497594  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000029 (ops 141-145)
I20260812 06:18:27.497630  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000030 (ops 146-150)
I20260812 06:18:27.497665  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000031 (ops 151-155)
I20260812 06:18:27.497700  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000032 (ops 156-160)
I20260812 06:18:27.497733  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000033 (ops 161-165)
I20260812 06:18:27.497768  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000034 (ops 166-170)
I20260812 06:18:27.497805  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000035 (ops 171-175)
I20260812 06:18:27.497841  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000036 (ops 176-180)
I20260812 06:18:27.497876  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000037 (ops 181-185)
I20260812 06:18:27.497912  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000038 (ops 186-190)
I20260812 06:18:27.497946  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000039 (ops 191-194)
I20260812 06:18:27.497983  1523 log.cc:1079] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: Deleting log segment in path: /tmp/dist-test-taskgUajPE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515496364742-1042-0/minicluster-data/ts-0-root/wals/5a73a6ba95804dc28bdf95890f6cbbb2/wal-000000040 (ops 195-199)
I20260812 06:18:27.530189  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: LogGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:27.530678  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=2.188937
I20260812 06:18:27.540148  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: FlushDeltaMemStoresOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3847,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":450}
I20260812 06:18:27.540576  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2): 493 bytes on disk
I20260812 06:18:27.540969  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: UndoDeltaBlockGCOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.541491  1625 maintenance_manager.cc:419] P db0d5fc05f6147f080f8c1c5a5f211ad: Scheduling MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2): perf score=1.000000
I20260812 06:18:27.559128  1042 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.001s	sys 0.000s
I20260812 06:18:27.559725  1042 tablet_server.cc:179] TabletServer@127.1.4.129:0 shutting down...
I20260812 06:18:27.665041  1523 maintenance_manager.cc:643] P db0d5fc05f6147f080f8c1c5a5f211ad: MajorDeltaCompactionOp(5a73a6ba95804dc28bdf95890f6cbbb2) complete. Timing: real 0.123s	user 0.111s	sys 0.012s Metrics: {"cfile_cache_hit":541,"cfile_cache_hit_bytes":24857211,"cfile_cache_miss":93,"cfile_cache_miss_bytes":4020109,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":232,"lbm_read_time_us":1731,"lbm_reads_lt_1ms":105,"lbm_write_time_us":30083,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:27.665957  1042 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:27.666332  1042 tablet_replica.cc:333] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad: stopping tablet replica
I20260812 06:18:27.666527  1042 raft_consensus.cc:2243] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:27.666749  1042 raft_consensus.cc:2272] T 5a73a6ba95804dc28bdf95890f6cbbb2 P db0d5fc05f6147f080f8c1c5a5f211ad [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:27.680755  1042 tablet_server.cc:196] TabletServer@127.1.4.129:0 shutdown complete.
I20260812 06:18:27.717010  1042 master.cc:562] Master@127.1.4.190:33553 shutting down...
I20260812 06:18:27.720448  1042 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:27.720652  1042 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:27.720734  1042 tablet_replica.cc:333] T 00000000000000000000000000000000 P 70dfe3b1d02a45999cf03f5e4f7512ab: stopping tablet replica
I20260812 06:18:27.733167  1042 master.cc:584] Master@127.1.4.190:33553 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5707 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11448 ms total)

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