[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:48.497121 23071 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.135.254:41001
I20260812 06:19:48.498075 23071 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:48.498652 23071 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.504547 23080 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.504637 23077 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.504813 23071 server_base.cc:1061] running on GCE node
W20260812 06:19:48.504841 23078 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.505259 23071 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.505378 23071 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:48.505442 23071 hybrid_clock.cc:648] HybridClock initialized: now 1786515588505440 us; error 0 us; skew 500 ppm
I20260812 06:19:48.507097 23071 webserver.cc:533] Webserver started at http://127.22.135.254:37155/ using document root <none> and password file <none>
I20260812 06:19:48.507609 23071 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.507695 23071 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.507934 23071 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.509560 23071 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/master-0-root/instance:
uuid: "0356e3b0ab834d8096ffedfe348ea269"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-2d19"
I20260812 06:19:48.512867 23071 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:48.514802 23093 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.515815 23071 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:48.515959 23071 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/master-0-root
uuid: "0356e3b0ab834d8096ffedfe348ea269"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-2d19"
I20260812 06:19:48.516064 23071 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:48.531992 23071 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.532843 23071 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:48.533057 23071 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.541126 23071 rpc_server.cc:307] RPC server started. Bound to: 127.22.135.254:41001
I20260812 06:19:48.541147 23192 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.135.254:41001 every 8 connection(s)
I20260812 06:19:48.543375 23194 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.548885 23194 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: Bootstrap starting.
I20260812 06:19:48.551231 23194 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.552137 23194 log.cc:826] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:48.553864 23194 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: No bootstrap required, opened a new log
I20260812 06:19:48.556639 23194 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER }
I20260812 06:19:48.556802 23194 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.556843 23194 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0356e3b0ab834d8096ffedfe348ea269, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.557384 23194 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [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: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER }
I20260812 06:19:48.557515 23194 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.557555 23194 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.557653 23194 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.558403 23194 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER }
I20260812 06:19:48.558830 23194 leader_election.cc:304] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [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: 0356e3b0ab834d8096ffedfe348ea269; no voters: 
I20260812 06:19:48.559113 23194 leader_election.cc:290] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.559273 23202 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.559548 23202 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 1 LEADER]: Becoming Leader. State: Replica: 0356e3b0ab834d8096ffedfe348ea269, State: Running, Role: LEADER
I20260812 06:19:48.559953 23202 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [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: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER }
I20260812 06:19:48.560209 23194 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:48.562094 23205 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0356e3b0ab834d8096ffedfe348ea269. Latest consensus state: current_term: 1 leader_uuid: "0356e3b0ab834d8096ffedfe348ea269" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER } }
I20260812 06:19:48.562194 23204 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0356e3b0ab834d8096ffedfe348ea269" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0356e3b0ab834d8096ffedfe348ea269" member_type: VOTER } }
I20260812 06:19:48.562215 23205 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.562302 23204 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.562665 23217 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:48.564970 23217 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:48.565250 23071 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:48.569625 23217 catalog_manager.cc:1383] Generated new cluster ID: 2dbe79c4d38b4677896533cc7aab9f71
I20260812 06:19:48.569694 23217 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:48.596582 23217 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:48.597479 23217 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:48.604928 23217 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: Generated new TSK 0
I20260812 06:19:48.605540 23217 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:48.630038 23071 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.632709 23237 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.632822 23238 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.632982 23071 server_base.cc:1061] running on GCE node
W20260812 06:19:48.633037 23241 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.633279 23071 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.633349 23071 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:48.633378 23071 hybrid_clock.cc:648] HybridClock initialized: now 1786515588633376 us; error 0 us; skew 500 ppm
I20260812 06:19:48.634343 23071 webserver.cc:533] Webserver started at http://127.22.135.193:36621/ using document root <none> and password file <none>
I20260812 06:19:48.634523 23071 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.634593 23071 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.634686 23071 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.635092 23071 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/instance:
uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-2d19"
I20260812 06:19:48.636719 23071 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:48.637746 23250 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.638001 23071 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:48.638078 23071 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root
uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-2d19"
I20260812 06:19:48.638167 23071 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:48.644712 23071 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.645102 23071 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.645619 23071 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:48.646485 23071 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:48.646538 23071 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.646605 23071 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:48.646652 23071 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.653528 23071 rpc_server.cc:307] RPC server started. Bound to: 127.22.135.193:38365
I20260812 06:19:48.653561 23376 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.135.193:38365 every 8 connection(s)
I20260812 06:19:48.666350 23377 heartbeater.cc:344] Connected to a master server at 127.22.135.254:41001
I20260812 06:19:48.666608 23377 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:48.667044 23377 heartbeater.cc:507] Master 127.22.135.254:41001 requested a full tablet report, sending...
I20260812 06:19:48.668443 23134 ts_manager.cc:194] Registered new tserver with Master: 74ca5ed9e978480f8a84cd3b05c9a9ab (127.22.135.193:38365)
I20260812 06:19:48.668655 23071 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014495531s
I20260812 06:19:48.669652 23134 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49796
I20260812 06:19:48.678212 23134 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49808:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:48.692345 23307 tablet_service.cc:1511] Processing CreateTablet for tablet 6d59b909ef474ca1b81c2a120b97a3d4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=478e19cbf1ce4ac8890c09e6f87e70d6]), partition=
I20260812 06:19:48.692807 23307 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6d59b909ef474ca1b81c2a120b97a3d4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.694957 23403 tablet_bootstrap.cc:492] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Bootstrap starting.
I20260812 06:19:48.696429 23403 tablet_bootstrap.cc:654] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.697700 23403 tablet_bootstrap.cc:492] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: No bootstrap required, opened a new log
I20260812 06:19:48.697804 23403 ts_tablet_manager.cc:1403] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:48.698316 23403 raft_consensus.cc:359] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 38365 } }
I20260812 06:19:48.698442 23403 raft_consensus.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.698477 23403 raft_consensus.cc:740] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74ca5ed9e978480f8a84cd3b05c9a9ab, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.698613 23403 consensus_queue.cc:260] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [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: "74ca5ed9e978480f8a84cd3b05c9a9ab" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 38365 } }
I20260812 06:19:48.698716 23403 raft_consensus.cc:399] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.698763 23403 raft_consensus.cc:493] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.698813 23403 raft_consensus.cc:3060] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.699769 23403 raft_consensus.cc:515] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 38365 } }
I20260812 06:19:48.699918 23403 leader_election.cc:304] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [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: 74ca5ed9e978480f8a84cd3b05c9a9ab; no voters: 
I20260812 06:19:48.700124 23403 leader_election.cc:290] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.700304 23406 raft_consensus.cc:2804] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.700500 23403 ts_tablet_manager.cc:1434] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:48.700533 23406 raft_consensus.cc:697] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 1 LEADER]: Becoming Leader. State: Replica: 74ca5ed9e978480f8a84cd3b05c9a9ab, State: Running, Role: LEADER
I20260812 06:19:48.700695 23406 consensus_queue.cc:237] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [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: "74ca5ed9e978480f8a84cd3b05c9a9ab" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 38365 } }
I20260812 06:19:48.700865 23377 heartbeater.cc:499] Master 127.22.135.254:41001 was elected leader, sending a full tablet report...
I20260812 06:19:48.703370 23134 catalog_manager.cc:5719] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab reported cstate change: term changed from 0 to 1, leader changed from <none> to 74ca5ed9e978480f8a84cd3b05c9a9ab (127.22.135.193). New cstate: current_term: 1 leader_uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ca5ed9e978480f8a84cd3b05c9a9ab" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 38365 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:48.768465 23071 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.024s	sys 0.003s
I20260812 06:19:48.904635 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=19.054940
I20260812 06:19:49.074033 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.169s	user 0.125s	sys 0.032s Metrics: {"bytes_written":12307493,"cfile_init":1,"compiler_manager_pool.queue_time_us":234,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41257,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":164,"threads_started":1,"update_count":1500}
I20260812 06:19:49.075027 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4): free 20743880 bytes of WAL
I20260812 06:19:49.075338 23265 log_reader.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4: removed 2 log segments from log reader
I20260812 06:19:49.075415 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000001 (ops 1-6)
I20260812 06:19:49.075487 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000002 (ops 7-11)
I20260812 06:19:49.079752 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:49.080081 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4): 16411392 bytes on disk
I20260812 06:19:49.080665 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.081030 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.096923 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.097394 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:49.237851 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.140s	user 0.098s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":7245,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25294,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":304,"threads_started":5,"update_count":2000}
I20260812 06:19:49.238941 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:49.299774 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.061s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22296,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.300386 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.315284 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.315814 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:49.452515 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.136s	user 0.100s	sys 0.036s 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":1438,"lbm_read_time_us":8417,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26833,"lbm_writes_lt_1ms":443,"mutex_wait_us":369,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:49.453052 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:49.492077 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.492537 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.512890 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.020s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.513496 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:49.630021 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.116s	user 0.081s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":419,"lbm_read_time_us":7153,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23118,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.630820 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=11.118625
I20260812 06:19:49.679843 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.049s	user 0.023s	sys 0.022s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21096,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.680351 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.694725 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.014s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.695196 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.704497 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3548,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.704938 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:49.883103 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.178s	user 0.110s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":222,"lbm_read_time_us":13056,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34464,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:49.883719 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:49.942267 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.058s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.943033 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:49.958822 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.959314 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:50.131306 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.172s	user 0.117s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":9664,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29449,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:50.131868 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:50.191978 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.060s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22203,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.192544 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.202760 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.203190 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:50.368485 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.165s	user 0.103s	sys 0.062s 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":90,"lbm_read_time_us":11657,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29307,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.369282 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:50.403213 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.034s	user 0.020s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12422,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:50.403694 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.418716 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.419342 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:50.449800 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.030s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1423,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1484,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:50.450614 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4): free 121006433 bytes of WAL
I20260812 06:19:50.450897 23265 log_reader.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4: removed 12 log segments from log reader
I20260812 06:19:50.450960 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000003 (ops 12-16)
I20260812 06:19:50.451002 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000004 (ops 17-21)
I20260812 06:19:50.451035 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000005 (ops 22-26)
I20260812 06:19:50.451057 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000006 (ops 27-31)
I20260812 06:19:50.451079 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000007 (ops 32-36)
I20260812 06:19:50.451114 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000008 (ops 37-40)
I20260812 06:19:50.451140 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000009 (ops 41-45)
I20260812 06:19:50.451162 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000010 (ops 46-50)
I20260812 06:19:50.451189 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000011 (ops 51-55)
I20260812 06:19:50.451216 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000012 (ops 56-60)
I20260812 06:19:50.451242 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000013 (ops 61-65)
I20260812 06:19:50.451277 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000014 (ops 66-70)
I20260812 06:19:50.478119 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:50.478530 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4): 482 bytes on disk
I20260812 06:19:50.479256 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.479810 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.505203 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.025s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.505637 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4): free 11564875 bytes of WAL
I20260812 06:19:50.505851 23265 log_reader.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4: removed 1 log segments from log reader
I20260812 06:19:50.505898 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000015 (ops 71-74)
I20260812 06:19:50.508074 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:50.508417 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.519493 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.520058 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:50.700802 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.181s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":370,"lbm_read_time_us":12329,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32371,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:50.701715 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:50.761773 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.060s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20684,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.762317 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.773195 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.773628 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:50.945850 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.172s	user 0.117s	sys 0.053s 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":131,"lbm_read_time_us":11987,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31194,"lbm_writes_lt_1ms":543,"mutex_wait_us":4,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:50.946446 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:50.981665 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.035s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15274,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.982185 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:50.997293 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.997714 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:51.155187 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.157s	user 0.101s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":9469,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26624,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:51.155769 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:51.197168 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.041s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.197672 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.207741 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.208525 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:51.334151 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.125s	user 0.098s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":9017,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24280,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:19:51.334995 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:51.374059 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.039s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.374627 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.384749 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.385289 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:51.505355 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.120s	user 0.104s	sys 0.016s 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":398,"lbm_read_time_us":9173,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22601,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:51.506129 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:51.555548 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.049s	user 0.027s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20439,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:51.556416 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.570057 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.570597 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:51.712028 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.141s	user 0.094s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":9093,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23856,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.712777 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=11.118625
I20260812 06:19:51.748529 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.036s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14824,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:51.749042 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.772109 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.023s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.772642 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.782503 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.782964 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:51.814548 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":142,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2153,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:51.815418 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4): 446 bytes on disk
I20260812 06:19:51.816020 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4) 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:19:51.817030 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:51.828855 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.829327 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4): free 112239316 bytes of WAL
I20260812 06:19:51.829564 23265 log_reader.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4: removed 11 log segments from log reader
I20260812 06:19:51.829609 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000016 (ops 75-79)
I20260812 06:19:51.829668 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000017 (ops 80-84)
I20260812 06:19:51.829713 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000018 (ops 85-89)
I20260812 06:19:51.829771 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000019 (ops 90-94)
I20260812 06:19:51.829811 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000020 (ops 95-99)
I20260812 06:19:51.829854 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000021 (ops 100-104)
I20260812 06:19:51.829895 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000022 (ops 105-109)
I20260812 06:19:51.829933 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000023 (ops 110-114)
I20260812 06:19:51.829972 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000024 (ops 115-118)
I20260812 06:19:51.830014 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000025 (ops 119-123)
I20260812 06:19:51.830054 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000026 (ops 124-128)
I20260812 06:19:51.854271 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:51.854653 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:52.039933 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.185s	user 0.134s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":741,"lbm_read_time_us":12732,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34752,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:52.040753 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=15.087375
I20260812 06:19:52.101430 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.060s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21473,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:52.101879 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=3.181125
I20260812 06:19:52.114295 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4882120,"delete_count":0,"lbm_write_time_us":5093,"lbm_writes_lt_1ms":122,"reinsert_count":0,"update_count":595}
I20260812 06:19:52.114816 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.196750
I20260812 06:19:52.122689 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":2948,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:19:52.123237 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:52.320771 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.197s	user 0.125s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877193,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":154,"lbm_read_time_us":15264,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36187,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":3000}
I20260812 06:19:52.321522 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:52.379463 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.058s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22001,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.380017 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:52.391758 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.392329 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:52.574116 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.182s	user 0.123s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":13527,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30349,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:52.574836 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:52.633602 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.059s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.634084 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:52.644848 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.645335 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:52.827054 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.182s	user 0.117s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":860,"lbm_read_time_us":13101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29320,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:52.827687 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=14.095187
I20260812 06:19:52.890236 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.062s	user 0.036s	sys 0.017s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20910,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.890863 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:52.901276 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.901885 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:53.075088 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.173s	user 0.134s	sys 0.039s 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":178,"lbm_read_time_us":12973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27289,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:53.075860 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:53.109464 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.033s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13527,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.110193 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:53.134845 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.024s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.135293 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:53.155789 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.020s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.156498 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:53.318534 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.162s	user 0.102s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774809,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":213,"lbm_read_time_us":11586,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27405,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:53.319397 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=11.118625
I20260812 06:19:53.355846 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15563,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:53.356465 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:53.370754 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4669,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.371297 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:53.420558 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushMRSOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.049s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1481,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1774,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:53.421226 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4): free 129320782 bytes of WAL
I20260812 06:19:53.421458 23265 log_reader.cc:385] T 6d59b909ef474ca1b81c2a120b97a3d4: removed 13 log segments from log reader
I20260812 06:19:53.421506 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000027 (ops 129-133)
I20260812 06:19:53.421535 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000028 (ops 134-138)
I20260812 06:19:53.421583 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000029 (ops 139-142)
I20260812 06:19:53.421626 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000030 (ops 143-147)
I20260812 06:19:53.421689 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000031 (ops 148-152)
I20260812 06:19:53.421731 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000032 (ops 153-156)
I20260812 06:19:53.421779 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000033 (ops 157-161)
I20260812 06:19:53.421818 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000034 (ops 162-166)
I20260812 06:19:53.421859 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000035 (ops 167-171)
I20260812 06:19:53.421900 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000036 (ops 172-176)
I20260812 06:19:53.421940 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000037 (ops 177-181)
I20260812 06:19:53.421981 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000038 (ops 182-186)
I20260812 06:19:53.422022 23265 log.cc:1079] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/6d59b909ef474ca1b81c2a120b97a3d4/wal-000000039 (ops 187-191)
I20260812 06:19:53.450170 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: LogGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:53.452984 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=6.157687
I20260812 06:19:53.481338 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.028s	user 0.022s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12438,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:53.481796 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4): 493 bytes on disk
I20260812 06:19:53.482187 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: UndoDeltaBlockGCOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.482702 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=2.188937
I20260812 06:19:53.492874 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.493467 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=1.000000
I20260812 06:19:53.627466 23071 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.859s	user 1.759s	sys 0.188s
I20260812 06:19:53.705310 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: MajorDeltaCompactionOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.212s	user 0.151s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15245,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38194,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3500}
I20260812 06:19:53.705792 23378 maintenance_manager.cc:419] P 74ca5ed9e978480f8a84cd3b05c9a9ab: Scheduling FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4): perf score=10.126437
I20260812 06:19:53.723810 23071 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.096s	user 0.002s	sys 0.000s
I20260812 06:19:53.724592 23071 tablet_server.cc:179] TabletServer@127.22.135.193:0 shutting down...
I20260812 06:19:53.752534 23265 maintenance_manager.cc:643] P 74ca5ed9e978480f8a84cd3b05c9a9ab: FlushDeltaMemStoresOp(6d59b909ef474ca1b81c2a120b97a3d4) complete. Timing: real 0.047s	user 0.027s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.753255 23071 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:53.753638 23071 tablet_replica.cc:333] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab: stopping tablet replica
I20260812 06:19:53.753875 23071 raft_consensus.cc:2243] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.754110 23071 raft_consensus.cc:2272] T 6d59b909ef474ca1b81c2a120b97a3d4 P 74ca5ed9e978480f8a84cd3b05c9a9ab [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.769536 23071 tablet_server.cc:196] TabletServer@127.22.135.193:0 shutdown complete.
I20260812 06:19:53.774387 23071 master.cc:562] Master@127.22.135.254:41001 shutting down...
I20260812 06:19:53.777897 23071 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.778084 23071 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.778187 23071 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0356e3b0ab834d8096ffedfe348ea269: stopping tablet replica
I20260812 06:19:53.790401 23071 master.cc:584] Master@127.22.135.254:41001 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5380 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:53.877112 23071 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.135.254:36101
I20260812 06:19:53.877542 23071 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.879673 23432 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.879813 23071 server_base.cc:1061] running on GCE node
W20260812 06:19:53.879822 23433 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.879698 23435 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.880123 23071 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.880189 23071 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.880215 23071 hybrid_clock.cc:648] HybridClock initialized: now 1786515593880214 us; error 0 us; skew 500 ppm
I20260812 06:19:53.881073 23071 webserver.cc:533] Webserver started at http://127.22.135.254:38101/ using document root <none> and password file <none>
I20260812 06:19:53.881249 23071 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.881316 23071 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.881405 23071 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.881791 23071 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/master-0-root/instance:
uuid: "28e33a169cf94917865f8164195ec1a6"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-2d19"
I20260812 06:19:53.883255 23071 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.884146 23442 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.884987 23071 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.885087 23071 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/master-0-root
uuid: "28e33a169cf94917865f8164195ec1a6"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-2d19"
I20260812 06:19:53.885178 23071 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.895620 23071 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.895990 23071 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.899933 23071 rpc_server.cc:307] RPC server started. Bound to: 127.22.135.254:36101
I20260812 06:19:53.902663 23556 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.135.254:36101 every 8 connection(s)
I20260812 06:19:53.903054 23557 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.910190 23557 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6: Bootstrap starting.
I20260812 06:19:53.910924 23557 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.911849 23557 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6: No bootstrap required, opened a new log
I20260812 06:19:53.912225 23557 raft_consensus.cc:359] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER }
I20260812 06:19:53.912376 23557 raft_consensus.cc:385] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.912403 23557 raft_consensus.cc:740] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 28e33a169cf94917865f8164195ec1a6, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.912549 23557 consensus_queue.cc:260] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [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: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER }
I20260812 06:19:53.912635 23557 raft_consensus.cc:399] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.912660 23557 raft_consensus.cc:493] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.912695 23557 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.913350 23557 raft_consensus.cc:515] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER }
I20260812 06:19:53.913465 23557 leader_election.cc:304] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [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: 28e33a169cf94917865f8164195ec1a6; no voters: 
I20260812 06:19:53.913600 23557 leader_election.cc:290] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.913775 23562 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.913955 23562 raft_consensus.cc:697] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 1 LEADER]: Becoming Leader. State: Replica: 28e33a169cf94917865f8164195ec1a6, State: Running, Role: LEADER
I20260812 06:19:53.914083 23562 consensus_queue.cc:237] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [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: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER }
I20260812 06:19:53.914112 23557 sys_catalog.cc:565] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:53.914552 23563 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "28e33a169cf94917865f8164195ec1a6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER } }
I20260812 06:19:53.914575 23564 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 28e33a169cf94917865f8164195ec1a6. Latest consensus state: current_term: 1 leader_uuid: "28e33a169cf94917865f8164195ec1a6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28e33a169cf94917865f8164195ec1a6" member_type: VOTER } }
I20260812 06:19:53.914654 23563 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.914664 23564 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.914913 23573 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:53.915716 23573 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:53.916101 23071 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:53.917490 23573 catalog_manager.cc:1383] Generated new cluster ID: d098a19b5ae34e7eb12eed64c0b19847
I20260812 06:19:53.917547 23573 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:53.927508 23573 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:53.928040 23573 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:53.934684 23573 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6: Generated new TSK 0
I20260812 06:19:53.934868 23573 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:53.948482 23071 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.950392 23597 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.950487 23598 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.950559 23071 server_base.cc:1061] running on GCE node
W20260812 06:19:53.950680 23602 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.950865 23071 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.950932 23071 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.950965 23071 hybrid_clock.cc:648] HybridClock initialized: now 1786515593950964 us; error 0 us; skew 500 ppm
I20260812 06:19:53.951730 23071 webserver.cc:533] Webserver started at http://127.22.135.193:44473/ using document root <none> and password file <none>
I20260812 06:19:53.951958 23071 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.952031 23071 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.952111 23071 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.952577 23071 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/instance:
uuid: "7cdfef4a56d94202ad4db335134044b5"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-2d19"
I20260812 06:19:53.954098 23071 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:53.955070 23609 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.955327 23071 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:53.955415 23071 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root
uuid: "7cdfef4a56d94202ad4db335134044b5"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-2d19"
I20260812 06:19:53.955504 23071 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.973584 23071 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.973994 23071 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.974328 23071 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.974812 23071 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.974875 23071 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.974926 23071 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.974977 23071 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.979513 23071 rpc_server.cc:307] RPC server started. Bound to: 127.22.135.193:40323
I20260812 06:19:53.980496 23729 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.135.193:40323 every 8 connection(s)
I20260812 06:19:53.989377 23734 heartbeater.cc:344] Connected to a master server at 127.22.135.254:36101
I20260812 06:19:53.989501 23734 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.989727 23734 heartbeater.cc:507] Master 127.22.135.254:36101 requested a full tablet report, sending...
I20260812 06:19:53.990368 23489 ts_manager.cc:194] Registered new tserver with Master: 7cdfef4a56d94202ad4db335134044b5 (127.22.135.193:40323)
I20260812 06:19:53.991035 23489 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49600
I20260812 06:19:53.991389 23071 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01094693s
I20260812 06:19:53.997778 23489 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49614:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:54.006552 23660 tablet_service.cc:1511] Processing CreateTablet for tablet a71b672aaa4e4fdda9d98ee266b7663f (DEFAULT_TABLE table=heavy-update-compaction-test [id=83d99be77a9c48ee9c8883131ae1746b]), partition=
I20260812 06:19:54.006875 23660 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a71b672aaa4e4fdda9d98ee266b7663f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.009030 23750 tablet_bootstrap.cc:492] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Bootstrap starting.
I20260812 06:19:54.009861 23750 tablet_bootstrap.cc:654] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.010828 23750 tablet_bootstrap.cc:492] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: No bootstrap required, opened a new log
I20260812 06:19:54.010900 23750 ts_tablet_manager.cc:1403] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:54.011248 23750 raft_consensus.cc:359] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cdfef4a56d94202ad4db335134044b5" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 40323 } }
I20260812 06:19:54.011332 23750 raft_consensus.cc:385] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.011353 23750 raft_consensus.cc:740] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7cdfef4a56d94202ad4db335134044b5, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.011456 23750 consensus_queue.cc:260] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [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: "7cdfef4a56d94202ad4db335134044b5" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 40323 } }
I20260812 06:19:54.011523 23750 raft_consensus.cc:399] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.011547 23750 raft_consensus.cc:493] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.011605 23750 raft_consensus.cc:3060] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.012614 23750 raft_consensus.cc:515] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cdfef4a56d94202ad4db335134044b5" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 40323 } }
I20260812 06:19:54.012728 23750 leader_election.cc:304] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [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: 7cdfef4a56d94202ad4db335134044b5; no voters: 
I20260812 06:19:54.012878 23750 leader_election.cc:290] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.013015 23754 raft_consensus.cc:2804] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.013238 23734 heartbeater.cc:499] Master 127.22.135.254:36101 was elected leader, sending a full tablet report...
I20260812 06:19:54.013219 23750 ts_tablet_manager.cc:1434] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:54.013226 23754 raft_consensus.cc:697] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 1 LEADER]: Becoming Leader. State: Replica: 7cdfef4a56d94202ad4db335134044b5, State: Running, Role: LEADER
I20260812 06:19:54.013450 23754 consensus_queue.cc:237] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [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: "7cdfef4a56d94202ad4db335134044b5" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 40323 } }
I20260812 06:19:54.014739 23489 catalog_manager.cc:5719] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7cdfef4a56d94202ad4db335134044b5 (127.22.135.193). New cstate: current_term: 1 leader_uuid: "7cdfef4a56d94202ad4db335134044b5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cdfef4a56d94202ad4db335134044b5" member_type: VOTER last_known_addr { host: "127.22.135.193" port: 40323 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:54.075404 23071 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.004s	sys 0.018s
I20260812 06:19:54.231020 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=22.031503
I20260812 06:19:54.383934 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.153s	user 0.114s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1011,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41211,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:54.384639 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f): free 20290830 bytes of WAL
I20260812 06:19:54.384857 23615 log_reader.cc:385] T a71b672aaa4e4fdda9d98ee266b7663f: removed 2 log segments from log reader
I20260812 06:19:54.384917 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000001 (ops 1-6)
I20260812 06:19:54.384972 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000002 (ops 7-10)
I20260812 06:19:54.389148 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:54.389513 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:54.405416 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.016s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.405881 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f): 20513815 bytes on disk
I20260812 06:19:54.406366 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.406847 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:54.548283 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.141s	user 0.083s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":10692,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":459,"lbm_write_time_us":24553,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":297,"threads_started":5,"update_count":2000}
I20260812 06:19:54.548976 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=11.118625
I20260812 06:19:54.585690 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.037s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15588,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:54.586341 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:54.598902 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.012s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.599418 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:54.719913 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.120s	user 0.098s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":7070,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22987,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:19:54.720472 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=11.118625
I20260812 06:19:54.767683 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.047s	user 0.016s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16359,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:54.768216 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:54.779253 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.779814 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:54.938251 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.158s	user 0.094s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":10540,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23960,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:19:54.938866 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:54.984164 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.045s	user 0.016s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.984726 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:54.995466 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.996110 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:55.159304 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.163s	user 0.112s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1014,"lbm_read_time_us":11644,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29009,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:19:55.159853 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:55.211104 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.051s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19926,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.211651 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:55.224956 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.225392 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:55.392409 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.167s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":830,"lbm_read_time_us":12719,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31728,"lbm_writes_lt_1ms":543,"mutex_wait_us":204,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:19:55.393280 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:55.445292 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.052s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22759,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.445892 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:55.456512 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.456970 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:55.597558 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":91,"lbm_read_time_us":10161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29599,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:19:55.598275 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=10.126437
I20260812 06:19:55.641746 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.041s	user 0.036s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16754,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.642367 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:55.657595 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5608,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.658293 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:55.689761 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.031s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1537,"drs_written":1,"lbm_read_time_us":126,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1666,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":2944}
I20260812 06:19:55.690810 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f): free 129320437 bytes of WAL
I20260812 06:19:55.691121 23615 log_reader.cc:385] T a71b672aaa4e4fdda9d98ee266b7663f: removed 13 log segments from log reader
I20260812 06:19:55.691223 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000003 (ops 11-15)
I20260812 06:19:55.691305 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000004 (ops 16-20)
I20260812 06:19:55.691372 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000005 (ops 21-24)
I20260812 06:19:55.691454 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000006 (ops 25-29)
I20260812 06:19:55.691522 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000007 (ops 30-34)
I20260812 06:19:55.691593 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000008 (ops 35-38)
I20260812 06:19:55.691663 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000009 (ops 39-43)
I20260812 06:19:55.691735 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000010 (ops 44-48)
I20260812 06:19:55.691805 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000011 (ops 49-53)
I20260812 06:19:55.691875 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000012 (ops 54-58)
I20260812 06:19:55.691977 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000013 (ops 59-63)
I20260812 06:19:55.692049 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000014 (ops 64-68)
I20260812 06:19:55.692118 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000015 (ops 69-73)
I20260812 06:19:55.723469 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.032s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:19:55.723899 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=6.157687
I20260812 06:19:55.743995 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.020s	user 0.018s	sys 0.000s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":8352,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:55.744464 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:55.913913 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.169s	user 0.116s	sys 0.050s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":10353,"lbm_read_time_us":12105,"lbm_reads_lt_1ms":669,"lbm_write_time_us":33917,"lbm_writes_lt_1ms":643,"mutex_wait_us":3335,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:55.914628 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:55.965344 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.050s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22617,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.965835 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f): 482 bytes on disk
I20260812 06:19:55.966223 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.966656 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:55.977687 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.978133 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:56.137358 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.159s	user 0.105s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":688,"lbm_read_time_us":10402,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29326,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.138043 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:56.193037 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.055s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":23958,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.193564 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:56.352632 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.159s	user 0.113s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":198,"lbm_read_time_us":10562,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23906,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:56.353197 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:56.409570 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.056s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24742,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.411082 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:56.426903 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.427402 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:56.604784 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.177s	user 0.113s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":11083,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30035,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2500}
I20260812 06:19:56.605466 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:56.680684 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.075s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":50285,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.681231 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:56.698195 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.698828 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:56.875989 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.177s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":10959,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32381,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:56.876662 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:56.927098 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.050s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19849,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.927701 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:56.938617 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.939127 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:57.087733 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.148s	user 0.110s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":10013,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28207,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:19:57.088544 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:57.138893 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.050s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19135,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.139401 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:57.150480 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.150940 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:57.180817 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1245,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:57.181428 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f): free 132571397 bytes of WAL
I20260812 06:19:57.181648 23615 log_reader.cc:385] T a71b672aaa4e4fdda9d98ee266b7663f: removed 13 log segments from log reader
I20260812 06:19:57.181711 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000016 (ops 74-78)
I20260812 06:19:57.181762 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000017 (ops 79-82)
I20260812 06:19:57.181821 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000018 (ops 83-87)
I20260812 06:19:57.181867 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000019 (ops 88-92)
I20260812 06:19:57.181906 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000020 (ops 93-97)
I20260812 06:19:57.181945 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000021 (ops 98-102)
I20260812 06:19:57.181983 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000022 (ops 103-106)
I20260812 06:19:57.182029 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000023 (ops 107-111)
I20260812 06:19:57.182070 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000024 (ops 112-116)
I20260812 06:19:57.182109 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000025 (ops 117-121)
I20260812 06:19:57.182147 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000026 (ops 122-126)
I20260812 06:19:57.182186 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000027 (ops 127-131)
I20260812 06:19:57.182225 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000028 (ops 132-136)
I20260812 06:19:57.209538 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:57.210008 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f): 481 bytes on disk
I20260812 06:19:57.210598 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.211366 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=6.157687
I20260812 06:19:57.232167 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":7835861,"delete_count":0,"lbm_write_time_us":8557,"lbm_writes_lt_1ms":194,"reinsert_count":0,"update_count":955}
I20260812 06:19:57.234542 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:57.453125 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.218s	user 0.154s	sys 0.059s Metrics: {"cfile_cache_miss":724,"cfile_cache_miss_bytes":32651410,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":272,"lbm_read_time_us":14293,"lbm_reads_lt_1ms":756,"lbm_write_time_us":35687,"lbm_writes_lt_1ms":734,"peak_mem_usage":86559345,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":71,"threads_started":1,"update_count":3455}
I20260812 06:19:57.453661 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=19.056125
I20260812 06:19:57.533340 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.079s	user 0.051s	sys 0.027s Metrics: {"bytes_written":20881536,"delete_count":0,"lbm_write_time_us":32013,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":510,"reinsert_count":0,"update_count":2545}
I20260812 06:19:57.533878 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=3.181125
I20260812 06:19:57.558806 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.025s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6813,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:57.559268 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:57.568686 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3705,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.569097 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:57.805403 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.236s	user 0.155s	sys 0.081s Metrics: {"cfile_cache_miss":742,"cfile_cache_miss_bytes":33389836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":344,"lbm_read_time_us":16674,"lbm_reads_lt_1ms":782,"lbm_write_time_us":40318,"lbm_writes_lt_1ms":752,"mutex_wait_us":29,"peak_mem_usage":88338359,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":3545}
I20260812 06:19:57.806097 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=16.079562
I20260812 06:19:57.877858 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.072s	user 0.026s	sys 0.028s Metrics: {"bytes_written":18297008,"delete_count":0,"lbm_write_time_us":23952,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":448,"reinsert_count":0,"update_count":2230}
I20260812 06:19:57.878337 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=5.165500
I20260812 06:19:57.897997 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.019s	user 0.006s	sys 0.012s Metrics: {"bytes_written":6317969,"delete_count":0,"lbm_write_time_us":7573,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:19:57.898514 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:58.104569 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.206s	user 0.110s	sys 0.093s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918094,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":642,"lbm_read_time_us":13937,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36096,"lbm_writes_lt_1ms":643,"mutex_wait_us":325,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:19:58.105253 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=18.063937
I20260812 06:19:58.169409 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.064s	user 0.038s	sys 0.024s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28923,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.169936 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:58.183029 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.183574 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:58.395012 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.211s	user 0.148s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":12974,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31509,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40704,"update_count":3000}
I20260812 06:19:58.399257 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=18.063937
I20260812 06:19:58.460403 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.061s	user 0.037s	sys 0.021s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24889,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.460875 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:58.472443 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.472932 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:58.685454 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.212s	user 0.141s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":371,"lbm_read_time_us":15959,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36439,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40448,"update_count":3000}
I20260812 06:19:58.686056 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=14.095187
I20260812 06:19:58.725926 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17741,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.726590 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:58.762310 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushMRSOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.036s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":154,"dirs.run_wall_time_us":1244,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2242,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:58.763159 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f): free 129320740 bytes of WAL
I20260812 06:19:58.763579 23615 log_reader.cc:385] T a71b672aaa4e4fdda9d98ee266b7663f: removed 13 log segments from log reader
I20260812 06:19:58.763644 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000029 (ops 137-141)
I20260812 06:19:58.763684 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000030 (ops 142-146)
I20260812 06:19:58.763716 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000031 (ops 147-151)
I20260812 06:19:58.763746 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000032 (ops 152-156)
I20260812 06:19:58.763768 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000033 (ops 157-160)
I20260812 06:19:58.763789 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000034 (ops 161-165)
I20260812 06:19:58.763810 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000035 (ops 166-170)
I20260812 06:19:58.763839 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000036 (ops 171-175)
I20260812 06:19:58.763870 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000037 (ops 176-180)
I20260812 06:19:58.763900 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000038 (ops 181-185)
I20260812 06:19:58.763937 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000039 (ops 186-190)
I20260812 06:19:58.763962 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000040 (ops 191-194)
I20260812 06:19:58.763986 23615 log.cc:1079] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: Deleting log segment in path: /tmp/dist-test-taskrV_bPh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588486846-23071-0/minicluster-data/ts-0-root/wals/a71b672aaa4e4fdda9d98ee266b7663f/wal-000000041 (ops 195-199)
I20260812 06:19:58.793720 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: LogGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:58.794157 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=3.181125
I20260812 06:19:58.811342 23071 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.736s	user 1.760s	sys 0.168s
I20260812 06:19:58.813305 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7095,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.813791 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=2.188937
I20260812 06:19:58.828859 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: FlushDeltaMemStoresOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5764,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.829571 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f): 483 bytes on disk
I20260812 06:19:58.830047 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: UndoDeltaBlockGCOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.830567 23735 maintenance_manager.cc:419] P 7cdfef4a56d94202ad4db335134044b5: Scheduling MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f): perf score=1.000000
I20260812 06:19:58.888044 23071 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:19:58.888616 23071 tablet_server.cc:179] TabletServer@127.22.135.193:0 shutting down...
I20260812 06:19:58.978335 23615 maintenance_manager.cc:643] P 7cdfef4a56d94202ad4db335134044b5: MajorDeltaCompactionOp(a71b672aaa4e4fdda9d98ee266b7663f) complete. Timing: real 0.148s	user 0.092s	sys 0.056s Metrics: {"cfile_cache_hit":264,"cfile_cache_hit_bytes":10751811,"cfile_cache_miss":369,"cfile_cache_miss_bytes":18166390,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1074,"lbm_read_time_us":7569,"lbm_reads_lt_1ms":401,"lbm_write_time_us":29403,"lbm_writes_lt_1ms":643,"mutex_wait_us":81,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33920,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:58.979066 23071 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.979418 23071 tablet_replica.cc:333] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5: stopping tablet replica
I20260812 06:19:58.979635 23071 raft_consensus.cc:2243] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.979830 23071 raft_consensus.cc:2272] T a71b672aaa4e4fdda9d98ee266b7663f P 7cdfef4a56d94202ad4db335134044b5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.984115 23071 tablet_server.cc:196] TabletServer@127.22.135.193:0 shutdown complete.
I20260812 06:19:59.029624 23071 master.cc:562] Master@127.22.135.254:36101 shutting down...
I20260812 06:19:59.033078 23071 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.033277 23071 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.033368 23071 tablet_replica.cc:333] T 00000000000000000000000000000000 P 28e33a169cf94917865f8164195ec1a6: stopping tablet replica
I20260812 06:19:59.045758 23071 master.cc:584] Master@127.22.135.254:36101 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5250 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10631 ms total)

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