[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:13.529914 27941 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.73.126:45055
I20260812 06:20:13.531076 27941 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:13.531824 27941 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:13.539646 27941 server_base.cc:1061] running on GCE node
W20260812 06:20:13.539655 27948 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.539538 27950 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.539937 27947 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.540566 27941 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.540666 27941 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:13.540695 27941 hybrid_clock.cc:648] HybridClock initialized: now 1786515613540693 us; error 0 us; skew 500 ppm
I20260812 06:20:13.542722 27941 webserver.cc:533] Webserver started at http://127.27.73.126:34937/ using document root <none> and password file <none>
I20260812 06:20:13.543277 27941 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.543335 27941 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.543622 27941 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.545399 27941 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/master-0-root/instance:
uuid: "186a7d214233497e99aea3fc34665272"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-c12x"
I20260812 06:20:13.549144 27941 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:13.551512 27955 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.552649 27941 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:13.552807 27941 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/master-0-root
uuid: "186a7d214233497e99aea3fc34665272"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-c12x"
I20260812 06:20:13.552949 27941 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:13.566727 27941 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.567386 27941 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:13.567622 27941 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.575361 27941 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.126:45055
I20260812 06:20:13.575408 28033 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.126:45055 every 8 connection(s)
I20260812 06:20:13.577875 28036 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:13.584028 28036 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: Bootstrap starting.
I20260812 06:20:13.586717 28036 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.587875 28036 log.cc:826] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:13.589927 28036 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: No bootstrap required, opened a new log
I20260812 06:20:13.593014 28036 raft_consensus.cc:359] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "186a7d214233497e99aea3fc34665272" member_type: VOTER }
I20260812 06:20:13.593204 28036 raft_consensus.cc:385] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.593276 28036 raft_consensus.cc:740] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 186a7d214233497e99aea3fc34665272, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.593910 28036 consensus_queue.cc:260] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [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: "186a7d214233497e99aea3fc34665272" member_type: VOTER }
I20260812 06:20:13.594067 28036 raft_consensus.cc:399] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.594153 28036 raft_consensus.cc:493] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.594323 28036 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.595180 28036 raft_consensus.cc:515] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "186a7d214233497e99aea3fc34665272" member_type: VOTER }
I20260812 06:20:13.595678 28036 leader_election.cc:304] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [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: 186a7d214233497e99aea3fc34665272; no voters: 
I20260812 06:20:13.596032 28036 leader_election.cc:290] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.596266 28040 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.596565 28040 raft_consensus.cc:697] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 1 LEADER]: Becoming Leader. State: Replica: 186a7d214233497e99aea3fc34665272, State: Running, Role: LEADER
I20260812 06:20:13.597004 28040 consensus_queue.cc:237] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [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: "186a7d214233497e99aea3fc34665272" member_type: VOTER }
I20260812 06:20:13.597153 28036 sys_catalog.cc:565] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:13.599071 28041 sys_catalog.cc:455] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "186a7d214233497e99aea3fc34665272" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "186a7d214233497e99aea3fc34665272" member_type: VOTER } }
I20260812 06:20:13.599051 28042 sys_catalog.cc:455] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 186a7d214233497e99aea3fc34665272. Latest consensus state: current_term: 1 leader_uuid: "186a7d214233497e99aea3fc34665272" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "186a7d214233497e99aea3fc34665272" member_type: VOTER } }
I20260812 06:20:13.599189 28042 sys_catalog.cc:458] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.599469 27941 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:13.599189 28041 sys_catalog.cc:458] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [sys.catalog]: This master's current role is: LEADER
W20260812 06:20:13.602097 28065 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:13.602210 28065 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:13.602288 28069 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:13.603067 28069 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:13.608754 28069 catalog_manager.cc:1383] Generated new cluster ID: 286bd0f79b5b4353a1e59de58fed74e0
I20260812 06:20:13.608844 28069 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:13.620239 28069 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:13.621898 28069 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:13.635195 28069 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: Generated new TSK 0
I20260812 06:20:13.636277 28069 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:13.664503 27941 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.667726 28082 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.667846 28077 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.667857 28076 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.668146 27941 server_base.cc:1061] running on GCE node
I20260812 06:20:13.668339 27941 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.668406 27941 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:13.668439 27941 hybrid_clock.cc:648] HybridClock initialized: now 1786515613668438 us; error 0 us; skew 500 ppm
I20260812 06:20:13.669457 27941 webserver.cc:533] Webserver started at http://127.27.73.65:38019/ using document root <none> and password file <none>
I20260812 06:20:13.669649 27941 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.669726 27941 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.669806 27941 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.670200 27941 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/instance:
uuid: "f74b0fecb24c4527a29f2bca53c9666b"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-c12x"
I20260812 06:20:13.671882 27941 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:13.672958 28089 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.673207 27941 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:13.673282 27941 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root
uuid: "f74b0fecb24c4527a29f2bca53c9666b"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-c12x"
I20260812 06:20:13.673377 27941 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:13.690248 27941 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.690804 27941 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.691371 27941 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:13.693028 27941 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:13.693094 27941 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.693181 27941 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:13.693224 27941 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.700554 27941 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.65:36903
I20260812 06:20:13.700575 28180 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.65:36903 every 8 connection(s)
I20260812 06:20:13.713416 28183 heartbeater.cc:344] Connected to a master server at 127.27.73.126:45055
I20260812 06:20:13.713706 28183 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:13.714215 28183 heartbeater.cc:507] Master 127.27.73.126:45055 requested a full tablet report, sending...
I20260812 06:20:13.715729 27978 ts_manager.cc:194] Registered new tserver with Master: f74b0fecb24c4527a29f2bca53c9666b (127.27.73.65:36903)
I20260812 06:20:13.716156 27941 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01485951s
I20260812 06:20:13.717204 27978 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47152
I20260812 06:20:13.726433 27978 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47154:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:13.744488 28130 tablet_service.cc:1511] Processing CreateTablet for tablet a815c93fc579466f9c789f1ebcf19c70 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e0383e13a1a54e3e8e5931862334b1c3]), partition=
I20260812 06:20:13.745023 28130 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a815c93fc579466f9c789f1ebcf19c70. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:13.748113 28200 tablet_bootstrap.cc:492] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Bootstrap starting.
I20260812 06:20:13.749253 28200 tablet_bootstrap.cc:654] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.751194 28200 tablet_bootstrap.cc:492] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: No bootstrap required, opened a new log
I20260812 06:20:13.751317 28200 ts_tablet_manager.cc:1403] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:13.751950 28200 raft_consensus.cc:359] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74b0fecb24c4527a29f2bca53c9666b" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 36903 } }
I20260812 06:20:13.752090 28200 raft_consensus.cc:385] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.752131 28200 raft_consensus.cc:740] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f74b0fecb24c4527a29f2bca53c9666b, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.752317 28200 consensus_queue.cc:260] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [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: "f74b0fecb24c4527a29f2bca53c9666b" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 36903 } }
I20260812 06:20:13.752434 28200 raft_consensus.cc:399] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.752488 28200 raft_consensus.cc:493] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.752532 28200 raft_consensus.cc:3060] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.753571 28200 raft_consensus.cc:515] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74b0fecb24c4527a29f2bca53c9666b" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 36903 } }
I20260812 06:20:13.753732 28200 leader_election.cc:304] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [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: f74b0fecb24c4527a29f2bca53c9666b; no voters: 
I20260812 06:20:13.753945 28200 leader_election.cc:290] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.754124 28202 raft_consensus.cc:2804] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.754277 28200 ts_tablet_manager.cc:1434] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:13.754529 28202 raft_consensus.cc:697] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 1 LEADER]: Becoming Leader. State: Replica: f74b0fecb24c4527a29f2bca53c9666b, State: Running, Role: LEADER
I20260812 06:20:13.754827 28183 heartbeater.cc:499] Master 127.27.73.126:45055 was elected leader, sending a full tablet report...
I20260812 06:20:13.755029 28202 consensus_queue.cc:237] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [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: "f74b0fecb24c4527a29f2bca53c9666b" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 36903 } }
I20260812 06:20:13.758082 27978 catalog_manager.cc:5719] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b reported cstate change: term changed from 0 to 1, leader changed from <none> to f74b0fecb24c4527a29f2bca53c9666b (127.27.73.65). New cstate: current_term: 1 leader_uuid: "f74b0fecb24c4527a29f2bca53c9666b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74b0fecb24c4527a29f2bca53c9666b" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 36903 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:13.825040 27941 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.025s	sys 0.004s
I20260812 06:20:13.951975 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70): perf score=15.086190
I20260812 06:20:14.139989 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.188s	user 0.154s	sys 0.032s Metrics: {"bytes_written":15999662,"cfile_init":1,"compiler_manager_pool.queue_time_us":231,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":2346,"drs_written":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48295,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":152,"threads_started":1,"update_count":1950}
I20260812 06:20:14.141176 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling LogGCOp(a815c93fc579466f9c789f1ebcf19c70): free 20743880 bytes of WAL
I20260812 06:20:14.141543 28097 log_reader.cc:385] T a815c93fc579466f9c789f1ebcf19c70: removed 2 log segments from log reader
I20260812 06:20:14.141656 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000001 (ops 1-6)
I20260812 06:20:14.141759 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000002 (ops 7-11)
I20260812 06:20:14.147105 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: LogGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:14.147506 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:14.170817 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.023s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.171337 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:14.186688 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.187275 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70): 12719216 bytes on disk
I20260812 06:20:14.188081 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.188627 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:14.403247 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.214s	user 0.143s	sys 0.061s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28466979,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":876,"lbm_read_time_us":15935,"lbm_reads_lt_1ms":659,"lbm_write_time_us":35085,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":319,"threads_started":5,"update_count":2950}
I20260812 06:20:14.403949 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:14.460860 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.057s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19779,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.461512 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:14.473527 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.474002 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:14.643955 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.170s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":12649,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30562,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:20:14.644604 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:14.685127 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.040s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17704,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.685840 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:14.696722 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.697162 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:14.833796 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.136s	user 0.107s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":786,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25883,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:14.834411 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:14.870227 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15028,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.870858 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:14.989523 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.118s	user 0.089s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1017,"lbm_read_time_us":5753,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22450,"lbm_writes_lt_1ms":343,"mutex_wait_us":288,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.990227 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:15.031251 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18555,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.031862 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:15.164938 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.133s	user 0.086s	sys 0.042s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":278,"lbm_read_time_us":9206,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22177,"lbm_writes_lt_1ms":343,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":1500}
I20260812 06:20:15.165454 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:15.203837 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.038s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14224,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:20:15.204532 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:15.320762 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.116s	user 0.090s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":217,"lbm_read_time_us":7900,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21671,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":1500}
I20260812 06:20:15.321247 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:15.359730 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.038s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.360256 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:15.463096 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.103s	user 0.098s	sys 0.004s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":263,"lbm_read_time_us":5815,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18424,"lbm_writes_lt_1ms":343,"mutex_wait_us":37,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":1500}
I20260812 06:20:15.463812 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:15.505836 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.042s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.506539 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:15.519552 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.520293 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:15.556519 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":313,"dirs.run_wall_time_us":1507,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1551,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:15.557545 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling LogGCOp(a815c93fc579466f9c789f1ebcf19c70): free 121006431 bytes of WAL
I20260812 06:20:15.557868 28097 log_reader.cc:385] T a815c93fc579466f9c789f1ebcf19c70: removed 12 log segments from log reader
I20260812 06:20:15.557941 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000003 (ops 12-16)
I20260812 06:20:15.557981 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000004 (ops 17-21)
I20260812 06:20:15.558009 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000005 (ops 22-26)
I20260812 06:20:15.558036 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000006 (ops 27-31)
I20260812 06:20:15.558109 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000007 (ops 32-36)
I20260812 06:20:15.558135 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000008 (ops 37-40)
I20260812 06:20:15.558156 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000009 (ops 41-45)
I20260812 06:20:15.558184 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000010 (ops 46-50)
I20260812 06:20:15.558214 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000011 (ops 51-55)
I20260812 06:20:15.558247 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000012 (ops 56-60)
I20260812 06:20:15.558279 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000013 (ops 61-65)
I20260812 06:20:15.558305 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000014 (ops 66-70)
I20260812 06:20:15.587901 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: LogGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:15.588339 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=3.181125
I20260812 06:20:15.608716 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.020s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4839,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:15.609516 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70): 473 bytes on disk
I20260812 06:20:15.610102 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.610822 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:15.627211 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.627733 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:15.826515 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.199s	user 0.124s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":608,"lbm_read_time_us":14518,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33001,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":153,"threads_started":1,"update_count":3000}
I20260812 06:20:15.827199 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:15.878732 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.051s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19040,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.879417 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:15.891116 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.891687 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.071187 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.179s	user 0.126s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":13146,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30283,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:16.071794 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:16.139602 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.068s	user 0.037s	sys 0.026s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23444,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.140193 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:16.156131 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.016s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.156702 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.341655 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.185s	user 0.133s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":15641,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30483,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:20:16.342293 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=11.118625
I20260812 06:20:16.382869 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.040s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17100,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.383571 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:16.396322 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4819,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.396888 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.525684 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.129s	user 0.096s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":8202,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24683,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.526196 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:16.567373 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.041s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15444,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.567909 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:16.579883 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.580508 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.713069 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":965,"lbm_read_time_us":8725,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26602,"lbm_writes_lt_1ms":443,"mutex_wait_us":272,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:16.713833 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:16.754278 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.040s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.754877 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:16.767210 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.767776 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.898521 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.130s	user 0.105s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":766,"lbm_read_time_us":7848,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26251,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:20:16.899312 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:16.940801 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.041s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14631,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.941463 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:16.953502 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.953999 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:16.994694 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.041s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1403,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:16.995812 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling LogGCOp(a815c93fc579466f9c789f1ebcf19c70): free 111786208 bytes of WAL
I20260812 06:20:16.996121 28097 log_reader.cc:385] T a815c93fc579466f9c789f1ebcf19c70: removed 11 log segments from log reader
I20260812 06:20:16.996193 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000015 (ops 71-74)
I20260812 06:20:16.996251 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000016 (ops 75-79)
I20260812 06:20:16.996315 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000017 (ops 80-84)
I20260812 06:20:16.996359 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000018 (ops 85-88)
I20260812 06:20:16.996397 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000019 (ops 89-93)
I20260812 06:20:16.996431 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000020 (ops 94-98)
I20260812 06:20:16.996470 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000021 (ops 99-103)
I20260812 06:20:16.996515 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000022 (ops 104-108)
I20260812 06:20:16.996546 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000023 (ops 109-113)
I20260812 06:20:16.996605 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000024 (ops 114-118)
I20260812 06:20:16.996649 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000025 (ops 119-123)
I20260812 06:20:17.019423 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: LogGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.023s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:17.019917 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70): 447 bytes on disk
I20260812 06:20:17.020782 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":275,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.021497 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:17.046294 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.025s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.046905 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:17.058048 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.058511 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:17.272585 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.214s	user 0.151s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1310,"lbm_read_time_us":14652,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35600,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15232,"thread_start_us":400,"threads_started":1,"update_count":3000}
I20260812 06:20:17.273784 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:17.336205 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.062s	user 0.046s	sys 0.006s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23140,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.336699 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:17.347862 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.348546 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:17.519304 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.171s	user 0.111s	sys 0.053s 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":870,"lbm_read_time_us":10779,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28693,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:20:17.519984 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:17.578213 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.058s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19201,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.578753 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:17.591228 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.592686 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:17.762880 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.170s	user 0.131s	sys 0.037s 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":1498,"lbm_read_time_us":12667,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30281,"lbm_writes_lt_1ms":543,"mutex_wait_us":483,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:17.763706 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=11.118625
I20260812 06:20:17.807934 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.044s	user 0.030s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18066,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:17.808516 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:17.828068 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.019s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7002,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.828569 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.004916 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.176s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":11923,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29728,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:18.005780 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=11.118625
I20260812 06:20:18.054682 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.049s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":22007,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.055280 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.067992 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.068511 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.080008 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.080559 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.238662 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.158s	user 0.127s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":674,"lbm_read_time_us":11831,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29810,"lbm_writes_lt_1ms":543,"mutex_wait_us":102,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:20:18.239552 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=11.118625
I20260812 06:20:18.281201 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18508,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.282230 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.300132 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.018s	user 0.012s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6682,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.300947 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.440037 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.139s	user 0.107s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":75,"lbm_read_time_us":7832,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27355,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:20:18.440789 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=10.126437
I20260812 06:20:18.484647 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.042s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18215,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.485248 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.500535 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6084,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.500991 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.538400 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushMRSOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.037s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1438,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1959,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:18.539556 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling LogGCOp(a815c93fc579466f9c789f1ebcf19c70): free 120553613 bytes of WAL
I20260812 06:20:18.539875 28097 log_reader.cc:385] T a815c93fc579466f9c789f1ebcf19c70: removed 12 log segments from log reader
I20260812 06:20:18.539948 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000026 (ops 124-128)
I20260812 06:20:18.539991 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000027 (ops 129-132)
I20260812 06:20:18.540071 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000028 (ops 133-137)
I20260812 06:20:18.540119 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000029 (ops 138-142)
I20260812 06:20:18.540148 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000030 (ops 143-146)
I20260812 06:20:18.540210 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000031 (ops 147-151)
I20260812 06:20:18.540246 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000032 (ops 152-156)
I20260812 06:20:18.540268 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000033 (ops 157-161)
I20260812 06:20:18.540313 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000034 (ops 162-166)
I20260812 06:20:18.540350 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000035 (ops 167-171)
I20260812 06:20:18.540401 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000036 (ops 172-176)
I20260812 06:20:18.540446 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000037 (ops 177-181)
I20260812 06:20:18.575031 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: LogGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.035s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:18.575625 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70): 463 bytes on disk
I20260812 06:20:18.576292 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: UndoDeltaBlockGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.577104 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=3.181125
I20260812 06:20:18.598634 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.021s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4841095,"delete_count":0,"lbm_write_time_us":8566,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:20:18.599568 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling LogGCOp(a815c93fc579466f9c789f1ebcf19c70): free 12018006 bytes of WAL
I20260812 06:20:18.599825 28097 log_reader.cc:385] T a815c93fc579466f9c789f1ebcf19c70: removed 1 log segments from log reader
I20260812 06:20:18.599884 28097 log.cc:1079] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/a815c93fc579466f9c789f1ebcf19c70/wal-000000038 (ops 182-186)
I20260812 06:20:18.603322 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: LogGCOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:18.603792 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.623234 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":5573,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:18.623742 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.810317 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.186s	user 0.146s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877321,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":894,"lbm_read_time_us":11767,"lbm_reads_lt_1ms":666,"lbm_write_time_us":37896,"lbm_writes_lt_1ms":643,"mutex_wait_us":333,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:18.812996 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=14.095187
I20260812 06:20:18.862715 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.049s	user 0.027s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21779,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.863511 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=2.188937
I20260812 06:20:18.879896 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.880501 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70): perf score=1.000000
I20260812 06:20:18.945855 27941 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.121s	user 1.869s	sys 0.168s
I20260812 06:20:19.022517 27941 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.002s	sys 0.000s
I20260812 06:20:19.032042 27941 tablet_server.cc:179] TabletServer@127.27.73.65:0 shutting down...
I20260812 06:20:19.032940 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: MajorDeltaCompactionOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.152s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1639,"lbm_read_time_us":9471,"lbm_reads_lt_1ms":560,"lbm_write_time_us":29864,"lbm_writes_lt_1ms":543,"mutex_wait_us":461,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:19.034044 28184 maintenance_manager.cc:419] P f74b0fecb24c4527a29f2bca53c9666b: Scheduling FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70): perf score=6.157687
I20260812 06:20:19.064476 28097 maintenance_manager.cc:643] P f74b0fecb24c4527a29f2bca53c9666b: FlushDeltaMemStoresOp(a815c93fc579466f9c789f1ebcf19c70) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13170,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:19.065542 27941 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.066107 27941 tablet_replica.cc:333] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b: stopping tablet replica
I20260812 06:20:19.066367 27941 raft_consensus.cc:2243] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.066640 27941 raft_consensus.cc:2272] T a815c93fc579466f9c789f1ebcf19c70 P f74b0fecb24c4527a29f2bca53c9666b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.074070 27941 tablet_server.cc:196] TabletServer@127.27.73.65:0 shutdown complete.
I20260812 06:20:19.080919 27941 master.cc:562] Master@127.27.73.126:45055 shutting down...
I20260812 06:20:19.087091 27941 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.087309 27941 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.087365 27941 tablet_replica.cc:333] T 00000000000000000000000000000000 P 186a7d214233497e99aea3fc34665272: stopping tablet replica
I20260812 06:20:19.102128 27941 master.cc:584] Master@127.27.73.126:45055 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5676 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:19.205402 27941 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.73.126:36147
I20260812 06:20:19.205781 27941 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:19.208676 27941 server_base.cc:1061] running on GCE node
W20260812 06:20:19.208914 28232 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.208922 28236 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.209162 28234 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.209431 27941 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.209487 27941 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.209508 27941 hybrid_clock.cc:648] HybridClock initialized: now 1786515619209508 us; error 0 us; skew 500 ppm
I20260812 06:20:19.211265 27941 webserver.cc:533] Webserver started at http://127.27.73.126:38865/ using document root <none> and password file <none>
I20260812 06:20:19.211627 27941 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.211705 27941 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.211782 27941 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.212499 27941 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/master-0-root/instance:
uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-c12x"
I20260812 06:20:19.214469 27941 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:19.216171 28242 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.216782 27941 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.216866 27941 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/master-0-root
uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-c12x"
I20260812 06:20:19.216944 27941 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.259212 27941 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.259856 27941 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.264956 27941 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.126:36147
I20260812 06:20:19.267948 28314 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.126:36147 every 8 connection(s)
I20260812 06:20:19.269523 28315 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.279175 28315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab: Bootstrap starting.
I20260812 06:20:19.280049 28315 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.281276 28315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab: No bootstrap required, opened a new log
I20260812 06:20:19.281888 28315 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER }
I20260812 06:20:19.281991 28315 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.282014 28315 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3a4ed26c00544bddb8ed99abe6c9a3ab, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.282125 28315 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [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: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER }
I20260812 06:20:19.282186 28315 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.282208 28315 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.282284 28315 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.283125 28315 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER }
I20260812 06:20:19.283252 28315 leader_election.cc:304] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [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: 3a4ed26c00544bddb8ed99abe6c9a3ab; no voters: 
I20260812 06:20:19.283550 28315 leader_election.cc:290] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.283900 28319 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.284132 28315 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.284178 28319 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 1 LEADER]: Becoming Leader. State: Replica: 3a4ed26c00544bddb8ed99abe6c9a3ab, State: Running, Role: LEADER
I20260812 06:20:19.284319 28319 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [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: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER }
I20260812 06:20:19.285022 28322 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3a4ed26c00544bddb8ed99abe6c9a3ab. Latest consensus state: current_term: 1 leader_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER } }
I20260812 06:20:19.285125 28322 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.285315 28321 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a4ed26c00544bddb8ed99abe6c9a3ab" member_type: VOTER } }
I20260812 06:20:19.285558 28321 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.285669 28325 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.286490 28325 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.287130 27941 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.288630 28325 catalog_manager.cc:1383] Generated new cluster ID: 378847cd8eff4ffb97f3db04d132a8c8
I20260812 06:20:19.288710 28325 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.308422 28325 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.309248 28325 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.316763 28325 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab: Generated new TSK 0
I20260812 06:20:19.316993 28325 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.320084 27941 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.322361 28350 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.322628 27941 server_base.cc:1061] running on GCE node
W20260812 06:20:19.322408 28345 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.322526 28348 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.322928 27941 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.322976 27941 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.322994 27941 hybrid_clock.cc:648] HybridClock initialized: now 1786515619322994 us; error 0 us; skew 500 ppm
I20260812 06:20:19.324062 27941 webserver.cc:533] Webserver started at http://127.27.73.65:34987/ using document root <none> and password file <none>
I20260812 06:20:19.324223 27941 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.324273 27941 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.324332 27941 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.324721 27941 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/instance:
uuid: "5817221ade1b4f8f8ec444058fd7e8b7"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-c12x"
I20260812 06:20:19.326596 27941 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.327970 28358 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.328485 27941 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.328600 27941 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root
uuid: "5817221ade1b4f8f8ec444058fd7e8b7"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-c12x"
I20260812 06:20:19.328701 27941 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.345479 27941 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.346302 27941 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.346925 27941 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.347649 27941 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.347818 27941 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.348058 27941 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.348120 27941 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.353976 27941 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.65:45567
I20260812 06:20:19.354374 28457 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.65:45567 every 8 connection(s)
I20260812 06:20:19.367098 28459 heartbeater.cc:344] Connected to a master server at 127.27.73.126:36147
I20260812 06:20:19.367270 28459 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.367586 28459 heartbeater.cc:507] Master 127.27.73.126:36147 requested a full tablet report, sending...
I20260812 06:20:19.368309 27941 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013718994s
I20260812 06:20:19.368305 28266 ts_manager.cc:194] Registered new tserver with Master: 5817221ade1b4f8f8ec444058fd7e8b7 (127.27.73.65:45567)
I20260812 06:20:19.369412 28266 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36582
I20260812 06:20:19.378937 28266 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36592:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:19.392030 28403 tablet_service.cc:1511] Processing CreateTablet for tablet c821b9156dfd47e1bb9b1914dac19d77 (DEFAULT_TABLE table=heavy-update-compaction-test [id=45e2dc7297c14c71a873fe5c0ccc936a]), partition=
I20260812 06:20:19.392442 28403 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c821b9156dfd47e1bb9b1914dac19d77. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.394974 28471 tablet_bootstrap.cc:492] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Bootstrap starting.
I20260812 06:20:19.396318 28471 tablet_bootstrap.cc:654] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.397797 28471 tablet_bootstrap.cc:492] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: No bootstrap required, opened a new log
I20260812 06:20:19.397883 28471 ts_tablet_manager.cc:1403] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.398322 28471 raft_consensus.cc:359] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5817221ade1b4f8f8ec444058fd7e8b7" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 45567 } }
I20260812 06:20:19.398415 28471 raft_consensus.cc:385] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.398438 28471 raft_consensus.cc:740] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5817221ade1b4f8f8ec444058fd7e8b7, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.398593 28471 consensus_queue.cc:260] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [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: "5817221ade1b4f8f8ec444058fd7e8b7" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 45567 } }
I20260812 06:20:19.398666 28471 raft_consensus.cc:399] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.398690 28471 raft_consensus.cc:493] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.398756 28471 raft_consensus.cc:3060] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.399652 28471 raft_consensus.cc:515] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5817221ade1b4f8f8ec444058fd7e8b7" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 45567 } }
I20260812 06:20:19.399801 28471 leader_election.cc:304] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [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: 5817221ade1b4f8f8ec444058fd7e8b7; no voters: 
I20260812 06:20:19.400050 28471 leader_election.cc:290] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.400238 28473 raft_consensus.cc:2804] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.400493 28471 ts_tablet_manager.cc:1434] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:19.400488 28473 raft_consensus.cc:697] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 1 LEADER]: Becoming Leader. State: Replica: 5817221ade1b4f8f8ec444058fd7e8b7, State: Running, Role: LEADER
I20260812 06:20:19.400488 28459 heartbeater.cc:499] Master 127.27.73.126:36147 was elected leader, sending a full tablet report...
I20260812 06:20:19.400748 28473 consensus_queue.cc:237] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [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: "5817221ade1b4f8f8ec444058fd7e8b7" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 45567 } }
I20260812 06:20:19.402359 28266 catalog_manager.cc:5719] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5817221ade1b4f8f8ec444058fd7e8b7 (127.27.73.65). New cstate: current_term: 1 leader_uuid: "5817221ade1b4f8f8ec444058fd7e8b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5817221ade1b4f8f8ec444058fd7e8b7" member_type: VOTER last_known_addr { host: "127.27.73.65" port: 45567 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.470410 27941 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.025s	sys 0.004s
I20260812 06:20:19.605175 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=15.086190
I20260812 06:20:19.756119 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.151s	user 0.105s	sys 0.040s Metrics: {"bytes_written":11897252,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1200,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37304,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:20:19.756868 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling LogGCOp(c821b9156dfd47e1bb9b1914dac19d77): free 20743880 bytes of WAL
I20260812 06:20:19.757128 28366 log_reader.cc:385] T c821b9156dfd47e1bb9b1914dac19d77: removed 2 log segments from log reader
I20260812 06:20:19.757176 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000001 (ops 1-6)
I20260812 06:20:19.757208 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000002 (ops 7-11)
I20260812 06:20:19.762257 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: LogGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:19.762758 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:19.777060 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.777521 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77): 12719216 bytes on disk
I20260812 06:20:19.777905 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.778295 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:19.927553 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.149s	user 0.093s	sys 0.056s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262039,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":10678,"lbm_reads_lt_1ms":450,"lbm_write_time_us":27543,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":386,"threads_started":5,"update_count":1950}
I20260812 06:20:19.928237 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:19.987336 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.059s	user 0.020s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19402,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.987972 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:19.999428 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4500,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.000173 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:20.159196 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.159s	user 0.114s	sys 0.044s 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":751,"lbm_read_time_us":12147,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23861,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:20:20.159911 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:20.216454 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.056s	user 0.025s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22145,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:20:20.217028 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:20.229661 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.012s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.230269 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:20.375342 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.145s	user 0.128s	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":623,"lbm_read_time_us":10915,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26861,"lbm_writes_lt_1ms":443,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:20:20.376158 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=11.118625
I20260812 06:20:20.412714 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.036s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16094,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.413288 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:20.426832 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4750,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.427409 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:20.570451 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.143s	user 0.117s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":8612,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27653,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:20:20.571288 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:20.618177 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.046s	user 0.023s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20433,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.618832 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:20.631405 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.632210 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:20.772607 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.140s	user 0.119s	sys 0.021s 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":899,"lbm_read_time_us":8867,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26700,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":134656,"update_count":2000}
I20260812 06:20:20.773231 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:20.830175 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.057s	user 0.030s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19338,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.830768 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:20.842422 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.842900 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:21.009837 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.167s	user 0.122s	sys 0.044s 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":628,"lbm_read_time_us":11175,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27510,"lbm_writes_lt_1ms":443,"mutex_wait_us":364,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":42112,"update_count":2000}
I20260812 06:20:21.010623 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:21.053237 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.042s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20123,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.053771 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:21.066093 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.066629 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:21.211622 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.145s	user 0.112s	sys 0.032s 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":319,"lbm_read_time_us":10438,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26559,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:20:21.212452 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=10.126437
I20260812 06:20:21.258200 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.046s	user 0.009s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.258713 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:21.271911 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.272437 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:21.310813 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1365,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2354,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:21.311537 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling LogGCOp(c821b9156dfd47e1bb9b1914dac19d77): free 121006437 bytes of WAL
I20260812 06:20:21.311815 28366 log_reader.cc:385] T c821b9156dfd47e1bb9b1914dac19d77: removed 12 log segments from log reader
I20260812 06:20:21.311875 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000003 (ops 12-16)
I20260812 06:20:21.311913 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000004 (ops 17-21)
I20260812 06:20:21.311942 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000005 (ops 22-26)
I20260812 06:20:21.311977 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000006 (ops 27-30)
I20260812 06:20:21.312002 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000007 (ops 31-35)
I20260812 06:20:21.312024 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000008 (ops 36-40)
I20260812 06:20:21.312053 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000009 (ops 41-45)
I20260812 06:20:21.312083 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000010 (ops 46-50)
I20260812 06:20:21.312116 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000011 (ops 51-55)
I20260812 06:20:21.312150 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000012 (ops 56-60)
I20260812 06:20:21.312179 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000013 (ops 61-65)
I20260812 06:20:21.312208 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000014 (ops 66-70)
I20260812 06:20:21.339773 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: LogGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:21.340180 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=3.181125
I20260812 06:20:21.353933 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5297,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.354444 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling LogGCOp(c821b9156dfd47e1bb9b1914dac19d77): free 11564875 bytes of WAL
I20260812 06:20:21.354705 28366 log_reader.cc:385] T c821b9156dfd47e1bb9b1914dac19d77: removed 1 log segments from log reader
I20260812 06:20:21.354825 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000015 (ops 71-74)
I20260812 06:20:21.357887 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: LogGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:21.358378 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:21.369484 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.370114 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:21.554144 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.184s	user 0.153s	sys 0.030s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":619,"lbm_read_time_us":12704,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38106,"lbm_writes_lt_1ms":643,"mutex_wait_us":274,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:20:21.554839 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77): 482 bytes on disk
I20260812 06:20:21.555385 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.556262 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:21.610716 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.054s	user 0.036s	sys 0.010s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22335,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.611424 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:21.627874 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.628389 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:21.801409 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.173s	user 0.136s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":348,"lbm_read_time_us":10489,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33458,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:20:21.802209 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=12.110812
I20260812 06:20:21.846737 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.044s	user 0.031s	sys 0.010s Metrics: {"bytes_written":13784349,"delete_count":0,"lbm_write_time_us":18733,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:20:21.847400 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.196750
I20260812 06:20:21.872381 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.025s	user 0.009s	sys 0.002s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:21.872936 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:21.883662 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:20:21.884260 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:22.085548 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.201s	user 0.131s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774767,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":193,"lbm_read_time_us":15197,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32252,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:20:22.086299 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:22.150305 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.064s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24621,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.150858 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:22.162137 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.162566 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:22.347906 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.185s	user 0.121s	sys 0.064s 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":287,"lbm_read_time_us":13308,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31354,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":96512,"update_count":2500}
I20260812 06:20:22.348487 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:22.409794 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.061s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20574,"lbm_writes_lt_1ms":403,"mutex_wait_us":141,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.410346 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:22.421643 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.422224 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:22.610642 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.188s	user 0.156s	sys 0.032s 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":1130,"lbm_read_time_us":12920,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30969,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:22.611584 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=11.118625
I20260812 06:20:22.654695 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.043s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17834,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.655563 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:22.693645 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.038s	user 0.006s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5313,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.694413 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:22.709372 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.710237 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:22.908664 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.198s	user 0.146s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1115,"lbm_read_time_us":15366,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28806,"lbm_writes_lt_1ms":543,"mutex_wait_us":349,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45952,"update_count":2500}
I20260812 06:20:22.909647 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:22.962999 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.053s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22472,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.963810 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:22.992925 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.029s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.993433 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:23.004652 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.005228 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:23.043737 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.038s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1357579,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1293,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1631,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:23.044389 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling LogGCOp(c821b9156dfd47e1bb9b1914dac19d77): free 129320550 bytes of WAL
I20260812 06:20:23.044620 28366 log_reader.cc:385] T c821b9156dfd47e1bb9b1914dac19d77: removed 13 log segments from log reader
I20260812 06:20:23.044661 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000016 (ops 75-79)
I20260812 06:20:23.044691 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000017 (ops 80-84)
I20260812 06:20:23.044756 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000018 (ops 85-89)
I20260812 06:20:23.044791 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000019 (ops 90-94)
I20260812 06:20:23.044831 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000020 (ops 95-98)
I20260812 06:20:23.044889 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000021 (ops 99-103)
I20260812 06:20:23.044925 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000022 (ops 104-108)
I20260812 06:20:23.044981 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000023 (ops 109-113)
I20260812 06:20:23.045022 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000024 (ops 114-118)
I20260812 06:20:23.045063 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000025 (ops 119-122)
I20260812 06:20:23.045101 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000026 (ops 123-127)
I20260812 06:20:23.045141 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000027 (ops 128-132)
I20260812 06:20:23.045182 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000028 (ops 133-137)
I20260812 06:20:23.072038 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: LogGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:23.072510 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77): 508 bytes on disk
I20260812 06:20:23.072939 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.073439 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=3.181125
I20260812 06:20:23.090875 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4536,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.091487 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:23.105639 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.106176 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:23.383496 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.277s	user 0.197s	sys 0.068s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":450,"lbm_read_time_us":20340,"lbm_reads_lt_1ms":875,"lbm_write_time_us":48017,"lbm_writes_lt_1ms":843,"mutex_wait_us":26,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":78,"threads_started":1,"update_count":4000}
I20260812 06:20:23.384380 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=22.032687
I20260812 06:20:23.464102 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.079s	user 0.051s	sys 0.028s Metrics: {"bytes_written":24614719,"delete_count":0,"lbm_write_time_us":36407,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:20:23.464958 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:23.480734 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.481208 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:23.685290 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.204s	user 0.143s	sys 0.059s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979506,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1803,"lbm_read_time_us":14125,"lbm_reads_lt_1ms":764,"lbm_write_time_us":44554,"lbm_writes_lt_1ms":743,"mutex_wait_us":999,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3500}
I20260812 06:20:23.686070 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=18.063937
I20260812 06:20:23.752735 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.066s	user 0.037s	sys 0.027s Metrics: {"bytes_written":20512323,"delete_count":0,"lbm_write_time_us":30291,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.753461 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:23.768772 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.769381 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:23.961376 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.192s	user 0.150s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":104,"lbm_read_time_us":13660,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38007,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:20:23.962349 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:24.014660 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.052s	user 0.044s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22694,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.015323 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:24.033160 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.018s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.033815 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:24.198032 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.164s	user 0.131s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":776,"lbm_read_time_us":9485,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30056,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:20:24.198797 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=13.103000
I20260812 06:20:24.249284 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.050s	user 0.028s	sys 0.020s Metrics: {"bytes_written":14809962,"delete_count":0,"lbm_write_time_us":19704,"lbm_writes_lt_1ms":364,"reinsert_count":0,"update_count":1805}
I20260812 06:20:24.249809 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:24.261574 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.012s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2010381,"delete_count":0,"lbm_write_time_us":2015,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:20:24.262117 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:24.272195 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3697,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.272801 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:24.457180 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.184s	user 0.121s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":846,"lbm_read_time_us":11985,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32159,"lbm_writes_lt_1ms":543,"mutex_wait_us":315,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:20:24.458058 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=14.095187
I20260812 06:20:24.520057 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.062s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25933,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.520568 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:24.532552 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.533389 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:24.571276 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushMRSOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":193,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2514,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:24.572103 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling LogGCOp(c821b9156dfd47e1bb9b1914dac19d77): free 124710570 bytes of WAL
I20260812 06:20:24.572345 28366 log_reader.cc:385] T c821b9156dfd47e1bb9b1914dac19d77: removed 12 log segments from log reader
I20260812 06:20:24.572387 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000029 (ops 138-142)
I20260812 06:20:24.572425 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000030 (ops 143-147)
I20260812 06:20:24.572494 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000031 (ops 148-152)
I20260812 06:20:24.572543 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000032 (ops 153-157)
I20260812 06:20:24.572580 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000033 (ops 158-162)
I20260812 06:20:24.572616 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000034 (ops 163-167)
I20260812 06:20:24.572655 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000035 (ops 168-172)
I20260812 06:20:24.572677 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000036 (ops 173-177)
I20260812 06:20:24.572734 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000037 (ops 178-182)
I20260812 06:20:24.572778 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000038 (ops 183-187)
I20260812 06:20:24.572821 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000039 (ops 188-192)
I20260812 06:20:24.572861 28366 log.cc:1079] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: Deleting log segment in path: /tmp/dist-test-taskoIGjyv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613517425-27941-0/minicluster-data/ts-0-root/wals/c821b9156dfd47e1bb9b1914dac19d77/wal-000000040 (ops 193-197)
I20260812 06:20:24.601181 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: LogGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:24.601727 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77): 472 bytes on disk
I20260812 06:20:24.602205 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: UndoDeltaBlockGCOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.602890 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:24.626055 27941 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.156s	user 1.909s	sys 0.140s
I20260812 06:20:24.627838 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.025s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.628357 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=2.188937
I20260812 06:20:24.639055 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: FlushDeltaMemStoresOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.639565 28460 maintenance_manager.cc:419] P 5817221ade1b4f8f8ec444058fd7e8b7: Scheduling MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77): perf score=1.000000
I20260812 06:20:24.708511 27941 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.003s	sys 0.001s
I20260812 06:20:24.709141 27941 tablet_server.cc:179] TabletServer@127.27.73.65:0 shutting down...
I20260812 06:20:24.815006 28366 maintenance_manager.cc:643] P 5817221ade1b4f8f8ec444058fd7e8b7: MajorDeltaCompactionOp(c821b9156dfd47e1bb9b1914dac19d77) complete. Timing: real 0.175s	user 0.110s	sys 0.065s Metrics: {"cfile_cache_hit":260,"cfile_cache_hit_bytes":10548056,"cfile_cache_miss":474,"cfile_cache_miss_bytes":22431694,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1728,"lbm_read_time_us":10100,"lbm_reads_lt_1ms":506,"lbm_write_time_us":35014,"lbm_writes_lt_1ms":743,"mutex_wait_us":400,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":439296,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:20:24.815932 27941 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.816200 27941 tablet_replica.cc:333] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7: stopping tablet replica
I20260812 06:20:24.816346 27941 raft_consensus.cc:2243] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.816556 27941 raft_consensus.cc:2272] T c821b9156dfd47e1bb9b1914dac19d77 P 5817221ade1b4f8f8ec444058fd7e8b7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.831125 27941 tablet_server.cc:196] TabletServer@127.27.73.65:0 shutdown complete.
I20260812 06:20:24.872825 27941 master.cc:562] Master@127.27.73.126:36147 shutting down...
I20260812 06:20:24.876989 27941 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.877182 27941 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.877229 27941 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3a4ed26c00544bddb8ed99abe6c9a3ab: stopping tablet replica
I20260812 06:20:24.890195 27941 master.cc:584] Master@127.27.73.126:36147 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5771 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11449 ms total)

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