[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:31.646847 11960 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.174.62:44101
I20260812 06:18:31.647958 11960 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:31.648589 11960 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:31.655301 11960 server_base.cc:1061] running on GCE node
W20260812 06:18:31.655251 11966 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:31.655251 11969 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:31.655589 11975 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:31.656157 11960 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:31.656267 11960 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:31.656312 11960 hybrid_clock.cc:648] HybridClock initialized: now 1786515511656309 us; error 0 us; skew 500 ppm
I20260812 06:18:31.658370 11960 webserver.cc:533] Webserver started at http://127.11.174.62:39109/ using document root <none> and password file <none>
I20260812 06:18:31.658978 11960 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:31.659053 11960 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:31.659301 11960 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:31.661243 11960 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/master-0-root/instance:
uuid: "063c36d62f3e418ab26a7438820bca5a"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-ncp9"
I20260812 06:18:31.665366 11960 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:31.667600 11982 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.668718 11960 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:31.668845 11960 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/master-0-root
uuid: "063c36d62f3e418ab26a7438820bca5a"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-ncp9"
I20260812 06:18:31.669013 11960 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:31.683851 11960 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:31.684578 11960 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:31.684762 11960 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:31.692946 11960 rpc_server.cc:307] RPC server started. Bound to: 127.11.174.62:44101
I20260812 06:18:31.692952 12064 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.174.62:44101 every 8 connection(s)
I20260812 06:18:31.695343 12067 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:31.701433 12067 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: Bootstrap starting.
I20260812 06:18:31.704670 12067 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:31.705875 12067 log.cc:826] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:31.707828 12067 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: No bootstrap required, opened a new log
I20260812 06:18:31.710886 12067 raft_consensus.cc:359] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER }
I20260812 06:18:31.711098 12067 raft_consensus.cc:385] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:31.711143 12067 raft_consensus.cc:740] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 063c36d62f3e418ab26a7438820bca5a, State: Initialized, Role: FOLLOWER
I20260812 06:18:31.711735 12067 consensus_queue.cc:260] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [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: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER }
I20260812 06:18:31.711877 12067 raft_consensus.cc:399] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:31.711925 12067 raft_consensus.cc:493] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:31.712031 12067 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:31.712990 12067 raft_consensus.cc:515] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER }
I20260812 06:18:31.713444 12067 leader_election.cc:304] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [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: 063c36d62f3e418ab26a7438820bca5a; no voters: 
I20260812 06:18:31.713740 12067 leader_election.cc:290] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:31.713876 12075 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:31.714094 12075 raft_consensus.cc:697] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 1 LEADER]: Becoming Leader. State: Replica: 063c36d62f3e418ab26a7438820bca5a, State: Running, Role: LEADER
I20260812 06:18:31.714535 12075 consensus_queue.cc:237] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [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: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER }
I20260812 06:18:31.714785 12067 sys_catalog.cc:565] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:31.716552 12076 sys_catalog.cc:455] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "063c36d62f3e418ab26a7438820bca5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER } }
I20260812 06:18:31.716558 12077 sys_catalog.cc:455] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 063c36d62f3e418ab26a7438820bca5a. Latest consensus state: current_term: 1 leader_uuid: "063c36d62f3e418ab26a7438820bca5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "063c36d62f3e418ab26a7438820bca5a" member_type: VOTER } }
I20260812 06:18:31.716701 12077 sys_catalog.cc:458] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:31.716701 12076 sys_catalog.cc:458] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:31.717038 11960 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:31.719139 12097 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:31.719211 12097 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:31.719384 12096 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:31.720541 12096 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:31.727104 12096 catalog_manager.cc:1383] Generated new cluster ID: 5660440110f4495c8860cd12782c422c
I20260812 06:18:31.727208 12096 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:31.741590 12096 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:31.742542 12096 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:31.749742 12096 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: Generated new TSK 0
I20260812 06:18:31.750429 12096 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:31.782305 11960 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:31.785346 12103 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:31.785465 12107 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:31.785524 12105 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:31.785663 11960 server_base.cc:1061] running on GCE node
I20260812 06:18:31.785987 11960 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:31.786051 11960 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:31.786074 11960 hybrid_clock.cc:648] HybridClock initialized: now 1786515511786074 us; error 0 us; skew 500 ppm
I20260812 06:18:31.787104 11960 webserver.cc:533] Webserver started at http://127.11.174.1:34683/ using document root <none> and password file <none>
I20260812 06:18:31.787289 11960 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:31.787350 11960 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:31.787487 11960 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:31.788005 11960 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/instance:
uuid: "11f2dcb51d264212beb9ea0142c149aa"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-ncp9"
I20260812 06:18:31.790257 11960 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:31.791594 12113 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.791980 11960 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:31.792074 11960 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root
uuid: "11f2dcb51d264212beb9ea0142c149aa"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-ncp9"
I20260812 06:18:31.792158 11960 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:31.803392 11960 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:31.803990 11960 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:31.804672 11960 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:31.805898 11960 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:31.805974 11960 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.806035 11960 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:31.806067 11960 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.813699 11960 rpc_server.cc:307] RPC server started. Bound to: 127.11.174.1:36545
I20260812 06:18:31.813803 12207 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.174.1:36545 every 8 connection(s)
I20260812 06:18:31.829763 12208 heartbeater.cc:344] Connected to a master server at 127.11.174.62:44101
I20260812 06:18:31.830080 12208 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:31.830668 12208 heartbeater.cc:507] Master 127.11.174.62:44101 requested a full tablet report, sending...
I20260812 06:18:31.832460 12009 ts_manager.cc:194] Registered new tserver with Master: 11f2dcb51d264212beb9ea0142c149aa (127.11.174.1:36545)
I20260812 06:18:31.832690 11960 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018265925s
I20260812 06:18:31.833850 12009 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55982
I20260812 06:18:31.844504 12009 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55984:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:31.860280 12155 tablet_service.cc:1511] Processing CreateTablet for tablet cdf5d1ad46c2416099ece27806f897a3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d1c4013a39cd46248f6b21fe08f2c0c4]), partition=
I20260812 06:18:31.860838 12155 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cdf5d1ad46c2416099ece27806f897a3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:31.864079 12225 tablet_bootstrap.cc:492] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Bootstrap starting.
I20260812 06:18:31.865624 12225 tablet_bootstrap.cc:654] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:31.867290 12225 tablet_bootstrap.cc:492] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: No bootstrap required, opened a new log
I20260812 06:18:31.867455 12225 ts_tablet_manager.cc:1403] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:31.868144 12225 raft_consensus.cc:359] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11f2dcb51d264212beb9ea0142c149aa" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 36545 } }
I20260812 06:18:31.868301 12225 raft_consensus.cc:385] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:31.868397 12225 raft_consensus.cc:740] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 11f2dcb51d264212beb9ea0142c149aa, State: Initialized, Role: FOLLOWER
I20260812 06:18:31.868634 12225 consensus_queue.cc:260] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [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: "11f2dcb51d264212beb9ea0142c149aa" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 36545 } }
I20260812 06:18:31.868755 12225 raft_consensus.cc:399] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:31.868808 12225 raft_consensus.cc:493] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:31.868862 12225 raft_consensus.cc:3060] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:31.870055 12225 raft_consensus.cc:515] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11f2dcb51d264212beb9ea0142c149aa" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 36545 } }
I20260812 06:18:31.870237 12225 leader_election.cc:304] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [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: 11f2dcb51d264212beb9ea0142c149aa; no voters: 
I20260812 06:18:31.870522 12225 leader_election.cc:290] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:31.870704 12229 raft_consensus.cc:2804] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:31.870935 12229 raft_consensus.cc:697] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 1 LEADER]: Becoming Leader. State: Replica: 11f2dcb51d264212beb9ea0142c149aa, State: Running, Role: LEADER
I20260812 06:18:31.871088 12225 ts_tablet_manager.cc:1434] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Time spent starting tablet: real 0.004s	user 0.000s	sys 0.004s
I20260812 06:18:31.871332 12208 heartbeater.cc:499] Master 127.11.174.62:44101 was elected leader, sending a full tablet report...
I20260812 06:18:31.871140 12229 consensus_queue.cc:237] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [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: "11f2dcb51d264212beb9ea0142c149aa" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 36545 } }
I20260812 06:18:31.874581 12008 catalog_manager.cc:5719] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa reported cstate change: term changed from 0 to 1, leader changed from <none> to 11f2dcb51d264212beb9ea0142c149aa (127.11.174.1). New cstate: current_term: 1 leader_uuid: "11f2dcb51d264212beb9ea0142c149aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11f2dcb51d264212beb9ea0142c149aa" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 36545 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:31.939680 11960 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.007s	sys 0.020s
I20260812 06:18:32.065059 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3): perf score=15.086190
I20260812 06:18:32.224256 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.159s	user 0.102s	sys 0.045s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":262,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":972,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39333,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":134,"threads_started":1,"update_count":1450}
I20260812 06:18:32.225569 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:32.238013 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.012s	user 0.002s	sys 0.005s Metrics: {"bytes_written":1353981,"delete_count":0,"lbm_write_time_us":2362,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:18:32.238745 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling LogGCOp(cdf5d1ad46c2416099ece27806f897a3): free 20743880 bytes of WAL
I20260812 06:18:32.239190 12120 log_reader.cc:385] T cdf5d1ad46c2416099ece27806f897a3: removed 2 log segments from log reader
I20260812 06:18:32.239347 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000001 (ops 1-6)
I20260812 06:18:32.239519 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000002 (ops 7-11)
I20260812 06:18:32.245134 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: LogGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:32.245632 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3): 12719214 bytes on disk
I20260812 06:18:32.246382 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.246922 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.196750
I20260812 06:18:32.259711 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":4677,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:18:32.260501 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:32.391601 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.131s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20262061,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":628,"lbm_read_time_us":10758,"lbm_reads_lt_1ms":451,"lbm_write_time_us":23975,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":283,"threads_started":5,"update_count":1950}
I20260812 06:18:32.392251 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:32.426646 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.034s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14493,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.427196 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:32.446462 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.019s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.447058 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:32.569406 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":8103,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23123,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":94336,"update_count":2000}
I20260812 06:18:32.570011 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:32.607695 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.038s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16348,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.608264 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:32.620438 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.621111 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:32.751237 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.130s	user 0.125s	sys 0.005s 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":286,"lbm_read_time_us":10509,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25328,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:18:32.751837 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:32.795224 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.043s	user 0.015s	sys 0.026s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14614,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.795842 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:32.813086 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.017s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.813791 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:32.969177 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.155s	user 0.106s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1113,"lbm_read_time_us":12100,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27255,"lbm_writes_lt_1ms":443,"mutex_wait_us":363,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:18:32.973229 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:33.014258 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.041s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14171,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.014896 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:33.025864 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.026613 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:33.152295 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.125s	user 0.113s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1033,"lbm_read_time_us":9461,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23357,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:18:33.152880 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:33.192715 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.040s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16119,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.193311 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:33.209451 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.209966 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:33.335320 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.125s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":10330,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24441,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:33.335920 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:33.374743 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17062,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.375319 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:33.393611 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.394223 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:33.527393 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.133s	user 0.102s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":712,"lbm_read_time_us":9679,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27509,"lbm_writes_lt_1ms":443,"mutex_wait_us":337,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.528328 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:33.572265 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.043s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14241,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.573050 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:33.589146 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.589779 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:33.636058 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.046s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1299,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1628,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:33.637179 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling LogGCOp(cdf5d1ad46c2416099ece27806f897a3): free 121006442 bytes of WAL
I20260812 06:18:33.637449 12120 log_reader.cc:385] T cdf5d1ad46c2416099ece27806f897a3: removed 12 log segments from log reader
I20260812 06:18:33.637518 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000003 (ops 12-16)
I20260812 06:18:33.637562 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000004 (ops 17-21)
I20260812 06:18:33.637586 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000005 (ops 22-26)
I20260812 06:18:33.637609 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000006 (ops 27-31)
I20260812 06:18:33.637631 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000007 (ops 32-36)
I20260812 06:18:33.637665 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000008 (ops 37-40)
I20260812 06:18:33.637697 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000009 (ops 41-45)
I20260812 06:18:33.637722 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000010 (ops 46-50)
I20260812 06:18:33.637750 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000011 (ops 51-55)
I20260812 06:18:33.637780 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000012 (ops 56-60)
I20260812 06:18:33.637813 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000013 (ops 61-65)
I20260812 06:18:33.637844 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000014 (ops 66-70)
I20260812 06:18:33.665068 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: LogGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:33.665593 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=3.181125
I20260812 06:18:33.678639 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:33.679103 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:33.688838 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3444,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.689312 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:33.917124 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.228s	user 0.145s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877332,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":994,"lbm_read_time_us":16493,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40456,"lbm_writes_lt_1ms":643,"mutex_wait_us":370,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:18:33.917879 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=14.095187
I20260812 06:18:33.962517 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19929,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.963068 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3): 483 bytes on disk
I20260812 06:18:33.963691 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.964242 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:34.118685 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.154s	user 0.102s	sys 0.051s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":169,"lbm_read_time_us":12060,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25722,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:34.121359 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:34.156950 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15777,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.157544 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:34.171931 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5395,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.172520 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:34.309841 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.137s	user 0.101s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":412,"lbm_read_time_us":10999,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23565,"lbm_writes_lt_1ms":443,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:34.310447 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:34.355201 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.045s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307519,"delete_count":0,"lbm_write_time_us":16833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.355829 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:34.367273 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.367798 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:34.499862 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.132s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672306,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":9092,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24985,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:34.500463 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:34.546347 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.046s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.546867 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:34.559273 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.012s	user 0.009s	sys 0.000s 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:18:34.560032 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:34.691617 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.131s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":644,"lbm_read_time_us":11370,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23719,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:18:34.692101 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:34.737033 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.045s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16592,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.737789 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:34.754766 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.755353 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:34.913906 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.158s	user 0.102s	sys 0.056s 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":858,"lbm_read_time_us":12034,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25708,"lbm_writes_lt_1ms":443,"mutex_wait_us":327,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.914614 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:34.945829 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.031s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13536,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.946376 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:34.962327 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.962805 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.089054 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.126s	user 0.102s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":548,"lbm_read_time_us":8925,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24872,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.089622 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:35.123673 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.034s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14326,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.124235 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:35.137205 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.137943 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.164364 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":141,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1906,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1401,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:35.165343 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling LogGCOp(cdf5d1ad46c2416099ece27806f897a3): free 124710306 bytes of WAL
I20260812 06:18:35.165627 12120 log_reader.cc:385] T cdf5d1ad46c2416099ece27806f897a3: removed 12 log segments from log reader
I20260812 06:18:35.165685 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000015 (ops 71-75)
I20260812 06:18:35.165715 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000016 (ops 76-80)
I20260812 06:18:35.165732 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000017 (ops 81-85)
I20260812 06:18:35.165760 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000018 (ops 86-90)
I20260812 06:18:35.165786 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000019 (ops 91-95)
I20260812 06:18:35.165818 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000020 (ops 96-100)
I20260812 06:18:35.165838 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000021 (ops 101-105)
I20260812 06:18:35.165869 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000022 (ops 106-110)
I20260812 06:18:35.165900 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000023 (ops 111-115)
I20260812 06:18:35.165927 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000024 (ops 116-120)
I20260812 06:18:35.165959 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000025 (ops 121-125)
I20260812 06:18:35.165987 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000026 (ops 126-130)
I20260812 06:18:35.191058 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: LogGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:35.191519 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=3.181125
I20260812 06:18:35.207048 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:35.207515 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:35.218351 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3731,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.219269 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.391558 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.172s	user 0.147s	sys 0.021s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":763,"lbm_read_time_us":13632,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33699,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:35.392165 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=14.095187
I20260812 06:18:35.440675 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.048s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18170,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.441202 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3): 472 bytes on disk
I20260812 06:18:35.441603 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.442078 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:35.456317 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5536,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.457051 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.632766 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.175s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":10869,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31694,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2500}
I20260812 06:18:35.633381 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=14.095187
I20260812 06:18:35.676254 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.043s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19402,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.676756 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.815776 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.139s	user 0.099s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":161,"lbm_read_time_us":12563,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21983,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:35.816378 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:35.847321 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.031s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13509,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.847878 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:35.858424 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.858986 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:35.987181 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.128s	user 0.102s	sys 0.025s 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":1119,"lbm_read_time_us":8368,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25519,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:18:35.987829 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:36.031804 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.044s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20364,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.032321 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:36.050743 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.018s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.051344 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:36.190653 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.139s	user 0.107s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":650,"lbm_read_time_us":8358,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28942,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:36.191367 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:36.232272 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.041s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307488,"delete_count":0,"lbm_write_time_us":17220,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.233004 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:36.248090 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.249135 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:36.384662 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.135s	user 0.098s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1100,"lbm_read_time_us":10337,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26509,"lbm_writes_lt_1ms":443,"mutex_wait_us":363,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:18:36.385448 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:36.426167 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.040s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13967,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.426748 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:36.437652 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.438382 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:36.579730 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.141s	user 0.097s	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":1055,"lbm_read_time_us":10820,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23198,"lbm_writes_lt_1ms":443,"mutex_wait_us":345,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.580518 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=10.126437
I20260812 06:18:36.614965 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.034s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14153,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.615617 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=2.188937
I20260812 06:18:36.631752 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.632234 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:36.659531 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushMRSOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1706,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:36.660216 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling LogGCOp(cdf5d1ad46c2416099ece27806f897a3): free 136728511 bytes of WAL
I20260812 06:18:36.660449 12120 log_reader.cc:385] T cdf5d1ad46c2416099ece27806f897a3: removed 13 log segments from log reader
I20260812 06:18:36.660494 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000027 (ops 131-135)
I20260812 06:18:36.660531 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000028 (ops 136-140)
I20260812 06:18:36.660562 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000029 (ops 141-145)
I20260812 06:18:36.660595 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000030 (ops 146-150)
I20260812 06:18:36.660629 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000031 (ops 151-155)
I20260812 06:18:36.660662 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000032 (ops 156-160)
I20260812 06:18:36.660694 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000033 (ops 161-165)
I20260812 06:18:36.660725 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000034 (ops 166-170)
I20260812 06:18:36.660758 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000035 (ops 171-175)
I20260812 06:18:36.660790 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000036 (ops 176-180)
I20260812 06:18:36.660822 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000037 (ops 181-185)
I20260812 06:18:36.660856 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000038 (ops 186-190)
I20260812 06:18:36.660908 12120 log.cc:1079] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/cdf5d1ad46c2416099ece27806f897a3/wal-000000039 (ops 191-195)
I20260812 06:18:36.692677 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: LogGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.032s	user 0.010s	sys 0.019s Metrics: {}
I20260812 06:18:36.693367 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3): 483 bytes on disk
I20260812 06:18:36.694056 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: UndoDeltaBlockGCOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.694763 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3): perf score=6.157687
I20260812 06:18:36.722945 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: FlushDeltaMemStoresOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.028s	user 0.006s	sys 0.019s Metrics: {"bytes_written":7548690,"delete_count":0,"lbm_write_time_us":7614,"lbm_writes_lt_1ms":187,"reinsert_count":0,"update_count":920}
I20260812 06:18:36.723759 12209 maintenance_manager.cc:419] P 11f2dcb51d264212beb9ea0142c149aa: Scheduling MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3): perf score=1.000000
I20260812 06:18:36.814097 11960 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.874s	user 1.786s	sys 0.124s
I20260812 06:18:36.919626 11960 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.001s	sys 0.000s
I20260812 06:18:36.920266 11960 tablet_server.cc:179] TabletServer@127.11.174.1:0 shutting down...
I20260812 06:18:36.927999 12120 maintenance_manager.cc:643] P 11f2dcb51d264212beb9ea0142c149aa: MajorDeltaCompactionOp(cdf5d1ad46c2416099ece27806f897a3) complete. Timing: real 0.204s	user 0.138s	sys 0.064s Metrics: {"cfile_cache_miss":617,"cfile_cache_miss_bytes":28220833,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2356,"lbm_read_time_us":16110,"lbm_reads_lt_1ms":645,"lbm_write_time_us":32711,"lbm_writes_lt_1ms":627,"mutex_wait_us":1902,"peak_mem_usage":72805144,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":65,"threads_started":1,"update_count":2920}
I20260812 06:18:36.929543 11960 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:36.929934 11960 tablet_replica.cc:333] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa: stopping tablet replica
I20260812 06:18:36.930135 11960 raft_consensus.cc:2243] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:36.930338 11960 raft_consensus.cc:2272] T cdf5d1ad46c2416099ece27806f897a3 P 11f2dcb51d264212beb9ea0142c149aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:36.946673 11960 tablet_server.cc:196] TabletServer@127.11.174.1:0 shutdown complete.
I20260812 06:18:36.975957 11960 master.cc:562] Master@127.11.174.62:44101 shutting down...
I20260812 06:18:36.979751 11960 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:36.979921 11960 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:36.979974 11960 tablet_replica.cc:333] T 00000000000000000000000000000000 P 063c36d62f3e418ab26a7438820bca5a: stopping tablet replica
I20260812 06:18:36.992256 11960 master.cc:584] Master@127.11.174.62:44101 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5423 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:37.084190 11960 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.174.62:40397
I20260812 06:18:37.084687 11960 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:37.086795 12266 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:37.086951 12262 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:37.086841 12261 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:37.087123 11960 server_base.cc:1061] running on GCE node
I20260812 06:18:37.087280 11960 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:37.087316 11960 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:37.087335 11960 hybrid_clock.cc:648] HybridClock initialized: now 1786515517087335 us; error 0 us; skew 500 ppm
I20260812 06:18:37.088236 11960 webserver.cc:533] Webserver started at http://127.11.174.62:44327/ using document root <none> and password file <none>
I20260812 06:18:37.088410 11960 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:37.088461 11960 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:37.088544 11960 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:37.089644 11960 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/master-0-root/instance:
uuid: "6452eb2f98bb431bb25dfe422400f0dc"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-ncp9"
I20260812 06:18:37.091678 11960 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:37.092761 12277 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.093114 11960 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:37.093200 11960 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/master-0-root
uuid: "6452eb2f98bb431bb25dfe422400f0dc"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-ncp9"
I20260812 06:18:37.093283 11960 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:37.118834 11960 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:37.119292 11960 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:37.123648 11960 rpc_server.cc:307] RPC server started. Bound to: 127.11.174.62:40397
I20260812 06:18:37.128175 12351 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.174.62:40397 every 8 connection(s)
I20260812 06:18:37.128712 12352 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:37.130704 12352 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc: Bootstrap starting.
I20260812 06:18:37.131584 12352 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:37.132795 12352 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc: No bootstrap required, opened a new log
I20260812 06:18:37.133251 12352 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER }
I20260812 06:18:37.133345 12352 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:37.133368 12352 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6452eb2f98bb431bb25dfe422400f0dc, State: Initialized, Role: FOLLOWER
I20260812 06:18:37.133498 12352 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [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: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER }
I20260812 06:18:37.133587 12352 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:37.133618 12352 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:37.133651 12352 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:37.134375 12352 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER }
I20260812 06:18:37.134514 12352 leader_election.cc:304] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [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: 6452eb2f98bb431bb25dfe422400f0dc; no voters: 
I20260812 06:18:37.134677 12352 leader_election.cc:290] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:37.134824 12357 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:37.135026 12357 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 1 LEADER]: Becoming Leader. State: Replica: 6452eb2f98bb431bb25dfe422400f0dc, State: Running, Role: LEADER
I20260812 06:18:37.135139 12352 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:37.135178 12357 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [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: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER }
I20260812 06:18:37.135649 12360 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6452eb2f98bb431bb25dfe422400f0dc. Latest consensus state: current_term: 1 leader_uuid: "6452eb2f98bb431bb25dfe422400f0dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER } }
I20260812 06:18:37.135623 12359 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6452eb2f98bb431bb25dfe422400f0dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6452eb2f98bb431bb25dfe422400f0dc" member_type: VOTER } }
I20260812 06:18:37.135731 12360 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:37.135740 12359 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:37.136051 12365 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:37.136881 12365 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:37.137187 11960 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:37.139721 12365 catalog_manager.cc:1383] Generated new cluster ID: d64d033d40a44cff9c612d47e166e158
I20260812 06:18:37.139806 12365 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:37.158576 12365 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:37.159190 12365 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:37.163749 12365 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc: Generated new TSK 0
I20260812 06:18:37.163960 12365 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:37.170091 11960 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:37.172603 12382 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:37.173110 12383 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:37.173215 11960 server_base.cc:1061] running on GCE node
W20260812 06:18:37.173296 12385 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:37.173532 11960 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:37.173601 11960 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:37.173622 11960 hybrid_clock.cc:648] HybridClock initialized: now 1786515517173622 us; error 0 us; skew 500 ppm
I20260812 06:18:37.174655 11960 webserver.cc:533] Webserver started at http://127.11.174.1:45135/ using document root <none> and password file <none>
I20260812 06:18:37.174850 11960 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:37.174912 11960 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:37.174998 11960 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:37.175454 11960 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/instance:
uuid: "929bcd90b2a14cd283e34eec908cda8f"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-ncp9"
I20260812 06:18:37.177704 11960 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:37.179085 12394 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.179452 11960 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:37.179592 11960 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root
uuid: "929bcd90b2a14cd283e34eec908cda8f"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-ncp9"
I20260812 06:18:37.179677 11960 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:37.187038 11960 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:37.187449 11960 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:37.187731 11960 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:37.188210 11960 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:37.188248 11960 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.188294 11960 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:37.188321 11960 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.192415 11960 rpc_server.cc:307] RPC server started. Bound to: 127.11.174.1:35599
I20260812 06:18:37.193517 12489 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.174.1:35599 every 8 connection(s)
I20260812 06:18:37.203720 12490 heartbeater.cc:344] Connected to a master server at 127.11.174.62:40397
I20260812 06:18:37.203869 12490 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:37.204174 12490 heartbeater.cc:507] Master 127.11.174.62:40397 requested a full tablet report, sending...
I20260812 06:18:37.204941 12296 ts_manager.cc:194] Registered new tserver with Master: 929bcd90b2a14cd283e34eec908cda8f (127.11.174.1:35599)
I20260812 06:18:37.205530 11960 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012280561s
I20260812 06:18:37.205783 12296 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59804
I20260812 06:18:37.212843 12296 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59820:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:37.222030 12442 tablet_service.cc:1511] Processing CreateTablet for tablet c169e2d3653f4958a3d287062399309c (DEFAULT_TABLE table=heavy-update-compaction-test [id=a2cab9bc65cd42d7a34d10253398a3c5]), partition=
I20260812 06:18:37.222328 12442 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c169e2d3653f4958a3d287062399309c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:37.224309 12515 tablet_bootstrap.cc:492] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Bootstrap starting.
I20260812 06:18:37.225325 12515 tablet_bootstrap.cc:654] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:37.226605 12515 tablet_bootstrap.cc:492] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: No bootstrap required, opened a new log
I20260812 06:18:37.226714 12515 ts_tablet_manager.cc:1403] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:37.227195 12515 raft_consensus.cc:359] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "929bcd90b2a14cd283e34eec908cda8f" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 35599 } }
I20260812 06:18:37.227295 12515 raft_consensus.cc:385] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:37.227326 12515 raft_consensus.cc:740] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 929bcd90b2a14cd283e34eec908cda8f, State: Initialized, Role: FOLLOWER
I20260812 06:18:37.227476 12515 consensus_queue.cc:260] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [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: "929bcd90b2a14cd283e34eec908cda8f" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 35599 } }
I20260812 06:18:37.227589 12515 raft_consensus.cc:399] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:37.227624 12515 raft_consensus.cc:493] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:37.227664 12515 raft_consensus.cc:3060] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:37.228434 12515 raft_consensus.cc:515] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "929bcd90b2a14cd283e34eec908cda8f" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 35599 } }
I20260812 06:18:37.228572 12515 leader_election.cc:304] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [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: 929bcd90b2a14cd283e34eec908cda8f; no voters: 
I20260812 06:18:37.228756 12515 leader_election.cc:290] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:37.228942 12519 raft_consensus.cc:2804] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:37.229068 12515 ts_tablet_manager.cc:1434] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:37.229086 12519 raft_consensus.cc:697] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 1 LEADER]: Becoming Leader. State: Replica: 929bcd90b2a14cd283e34eec908cda8f, State: Running, Role: LEADER
I20260812 06:18:37.229141 12490 heartbeater.cc:499] Master 127.11.174.62:40397 was elected leader, sending a full tablet report...
I20260812 06:18:37.229281 12519 consensus_queue.cc:237] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [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: "929bcd90b2a14cd283e34eec908cda8f" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 35599 } }
I20260812 06:18:37.230739 12296 catalog_manager.cc:5719] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f reported cstate change: term changed from 0 to 1, leader changed from <none> to 929bcd90b2a14cd283e34eec908cda8f (127.11.174.1). New cstate: current_term: 1 leader_uuid: "929bcd90b2a14cd283e34eec908cda8f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "929bcd90b2a14cd283e34eec908cda8f" member_type: VOTER last_known_addr { host: "127.11.174.1" port: 35599 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:37.291445 11960 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:18:37.444288 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushMRSOp(c169e2d3653f4958a3d287062399309c): perf score=19.054940
I20260812 06:18:37.600338 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushMRSOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.156s	user 0.097s	sys 0.055s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":101,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":934,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40652,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:37.601085 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling LogGCOp(c169e2d3653f4958a3d287062399309c): free 20743880 bytes of WAL
I20260812 06:18:37.601311 12406 log_reader.cc:385] T c169e2d3653f4958a3d287062399309c: removed 2 log segments from log reader
I20260812 06:18:37.601359 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000001 (ops 1-6)
I20260812 06:18:37.601392 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000002 (ops 7-11)
I20260812 06:18:37.605212 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: LogGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:37.605691 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c): 16411393 bytes on disk
I20260812 06:18:37.606315 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":112,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.606840 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:37.620268 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.620659 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:37.781685 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.161s	user 0.093s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":11061,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23517,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"thread_start_us":312,"threads_started":5,"update_count":2000}
I20260812 06:18:37.782264 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=11.118625
I20260812 06:18:37.826560 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.042s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12799772,"delete_count":0,"lbm_write_time_us":18406,"lbm_writes_lt_1ms":315,"reinsert_count":0,"update_count":1560}
I20260812 06:18:37.827006 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:37.849851 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.023s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:18:37.850384 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:37.872766 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.022s	user 0.001s	sys 0.018s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.873848 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:38.066301 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.192s	user 0.105s	sys 0.087s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774786,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":146,"lbm_read_time_us":14996,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29884,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:18:38.066829 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=14.095187
I20260812 06:18:38.123745 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.057s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.124212 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:38.137975 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.138940 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:38.337062 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.198s	user 0.130s	sys 0.057s 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":1310,"lbm_read_time_us":14278,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31518,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:18:38.337695 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=11.118625
I20260812 06:18:38.370748 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.033s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13656,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:38.371388 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:38.384606 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5117,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.385236 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:38.509514 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.124s	user 0.093s	sys 0.029s 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":1785,"lbm_read_time_us":8057,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26249,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":651,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:38.510371 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:38.552322 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.042s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15680,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.552950 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:38.568830 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.569373 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:38.711025 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.141s	user 0.105s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":398,"lbm_read_time_us":10829,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27420,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:38.711712 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:38.768859 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21658,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.769565 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:38.782557 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.783180 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:38.950811 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.167s	user 0.125s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":633,"lbm_read_time_us":12928,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27439,"lbm_writes_lt_1ms":443,"mutex_wait_us":325,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:18:38.951467 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:38.986776 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.035s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14789,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.987421 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:39.005776 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.006467 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushMRSOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:39.037156 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushMRSOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.030s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1306,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1525,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:39.037840 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling LogGCOp(c169e2d3653f4958a3d287062399309c): free 124710247 bytes of WAL
I20260812 06:18:39.038095 12406 log_reader.cc:385] T c169e2d3653f4958a3d287062399309c: removed 12 log segments from log reader
I20260812 06:18:39.038151 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000003 (ops 12-16)
I20260812 06:18:39.038184 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000004 (ops 17-21)
I20260812 06:18:39.038218 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000005 (ops 22-26)
I20260812 06:18:39.038250 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000006 (ops 27-31)
I20260812 06:18:39.038282 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000007 (ops 32-36)
I20260812 06:18:39.038316 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000008 (ops 37-41)
I20260812 06:18:39.038339 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000009 (ops 42-46)
I20260812 06:18:39.038379 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000010 (ops 47-51)
I20260812 06:18:39.038411 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000011 (ops 52-56)
I20260812 06:18:39.038434 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000012 (ops 57-61)
I20260812 06:18:39.038465 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000013 (ops 62-66)
I20260812 06:18:39.038501 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000014 (ops 67-71)
I20260812 06:18:39.064258 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: LogGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:39.064755 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c): 483 bytes on disk
I20260812 06:18:39.065428 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.066048 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=6.157687
I20260812 06:18:39.101171 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.035s	user 0.019s	sys 0.015s Metrics: {"bytes_written":7671762,"delete_count":0,"lbm_write_time_us":11221,"lbm_writes_lt_1ms":190,"reinsert_count":0,"update_count":935}
I20260812 06:18:39.101912 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:39.318336 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.216s	user 0.152s	sys 0.061s Metrics: {"cfile_cache_miss":620,"cfile_cache_miss_bytes":28343904,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":567,"lbm_read_time_us":16503,"lbm_reads_lt_1ms":652,"lbm_write_time_us":35230,"lbm_writes_lt_1ms":630,"mutex_wait_us":297,"peak_mem_usage":73968633,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":75,"threads_started":1,"update_count":2935}
I20260812 06:18:39.318958 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=15.087375
I20260812 06:18:39.371526 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.052s	user 0.027s	sys 0.023s Metrics: {"bytes_written":17353464,"delete_count":0,"lbm_write_time_us":18543,"lbm_writes_lt_1ms":426,"reinsert_count":0,"update_count":2115}
I20260812 06:18:39.372171 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:39.399437 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.027s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.399904 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:39.410010 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3624,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.410458 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:39.623932 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.213s	user 0.147s	sys 0.066s Metrics: {"cfile_cache_miss":646,"cfile_cache_miss_bytes":29410528,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":256,"lbm_read_time_us":15607,"lbm_reads_lt_1ms":686,"lbm_write_time_us":36283,"lbm_writes_lt_1ms":656,"mutex_wait_us":51,"peak_mem_usage":77116311,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3065}
I20260812 06:18:39.624480 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=14.095187
I20260812 06:18:39.671353 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.047s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.671919 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:39.682724 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.683307 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:39.857724 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.174s	user 0.111s	sys 0.055s 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":108,"lbm_read_time_us":12754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26307,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:18:39.858309 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=14.095187
I20260812 06:18:39.914361 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.056s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18018,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.914965 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:39.925390 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.925840 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:40.106684 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.181s	user 0.125s	sys 0.052s 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":220,"lbm_read_time_us":12843,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28403,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:40.107519 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=11.118625
I20260812 06:18:40.154125 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.046s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17448,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:40.154785 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:40.177771 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.023s	user 0.005s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.178388 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:40.188709 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.189410 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:40.367448 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.178s	user 0.132s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1144,"lbm_read_time_us":12577,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28149,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:40.368085 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=11.118625
I20260812 06:18:40.404860 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.037s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14897,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:40.405700 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:40.420723 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4586,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.421255 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:40.554984 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.134s	user 0.085s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":8358,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26010,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.555642 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:40.596009 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.040s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18146,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.596645 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:40.610594 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.611238 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushMRSOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:40.643119 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushMRSOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1305,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1429,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:40.643956 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling LogGCOp(c169e2d3653f4958a3d287062399309c): free 121006504 bytes of WAL
I20260812 06:18:40.644305 12406 log_reader.cc:385] T c169e2d3653f4958a3d287062399309c: removed 12 log segments from log reader
I20260812 06:18:40.644361 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000015 (ops 72-76)
I20260812 06:18:40.644402 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000016 (ops 77-81)
I20260812 06:18:40.644433 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000017 (ops 82-86)
I20260812 06:18:40.644467 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000018 (ops 87-91)
I20260812 06:18:40.644497 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000019 (ops 92-96)
I20260812 06:18:40.644528 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000020 (ops 97-101)
I20260812 06:18:40.644559 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000021 (ops 102-106)
I20260812 06:18:40.644588 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000022 (ops 107-110)
I20260812 06:18:40.644618 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000023 (ops 111-115)
I20260812 06:18:40.644650 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000024 (ops 116-120)
I20260812 06:18:40.644680 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000025 (ops 121-125)
I20260812 06:18:40.644709 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000026 (ops 126-130)
I20260812 06:18:40.670528 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: LogGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:40.671113 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c): 482 bytes on disk
I20260812 06:18:40.671655 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: UndoDeltaBlockGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.672464 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=5.165500
I20260812 06:18:40.692947 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.020s	user 0.017s	sys 0.003s Metrics: {"bytes_written":7425618,"delete_count":0,"lbm_write_time_us":8216,"lbm_writes_lt_1ms":184,"reinsert_count":0,"update_count":905}
I20260812 06:18:40.693573 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling LogGCOp(c169e2d3653f4958a3d287062399309c): free 12017949 bytes of WAL
I20260812 06:18:40.693917 12406 log_reader.cc:385] T c169e2d3653f4958a3d287062399309c: removed 1 log segments from log reader
I20260812 06:18:40.694015 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000027 (ops 131-135)
I20260812 06:18:40.696417 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: LogGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:40.696810 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:40.881502 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.184s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":614,"cfile_cache_miss_bytes":28097761,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":453,"lbm_read_time_us":12115,"lbm_reads_lt_1ms":650,"lbm_write_time_us":31667,"lbm_writes_lt_1ms":624,"peak_mem_usage":72682039,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":104,"threads_started":1,"update_count":2905}
I20260812 06:18:40.882190 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=16.079562
I20260812 06:18:40.977846 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.095s	user 0.035s	sys 0.004s Metrics: {"bytes_written":17599609,"delete_count":0,"lbm_write_time_us":16846,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2145}
I20260812 06:18:40.978439 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=6.157687
I20260812 06:18:41.079655 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.101s	user 0.017s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7866,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:41.080214 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=7.149875
I20260812 06:18:41.179073 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.099s	user 0.023s	sys 0.003s Metrics: {"bytes_written":9230683,"delete_count":0,"lbm_write_time_us":11251,"lbm_writes_lt_1ms":228,"reinsert_count":0,"update_count":1125}
I20260812 06:18:41.179652 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=5.165500
I20260812 06:18:41.283093 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.103s	user 0.008s	sys 0.009s Metrics: {"bytes_written":7179483,"delete_count":0,"lbm_write_time_us":7471,"lbm_writes_lt_1ms":178,"reinsert_count":0,"update_count":875}
I20260812 06:18:41.283766 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:41.391185 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.107s	user 0.028s	sys 0.008s Metrics: {"bytes_written":11856225,"delete_count":0,"lbm_write_time_us":16462,"lbm_writes_lt_1ms":292,"reinsert_count":0,"update_count":1445}
I20260812 06:18:41.391957 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=6.157687
I20260812 06:18:41.496407 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.104s	user 0.021s	sys 0.001s Metrics: {"bytes_written":8246106,"delete_count":0,"lbm_write_time_us":9487,"lbm_writes_lt_1ms":204,"reinsert_count":0,"update_count":1005}
I20260812 06:18:41.497067 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=7.149875
I20260812 06:18:41.599174 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.102s	user 0.005s	sys 0.016s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9209,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:41.599828 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=6.157687
I20260812 06:18:41.703310 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.103s	user 0.011s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7754,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:41.703943 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:41.808001 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.104s	user 0.027s	sys 0.004s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":13468,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:18:41.808555 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=7.149875
I20260812 06:18:41.912186 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.103s	user 0.013s	sys 0.008s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8803,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:41.912864 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=10.126437
I20260812 06:18:42.019556 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.106s	user 0.018s	sys 0.022s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":16326,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:18:42.020152 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=6.157687
I20260812 06:18:42.117553 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.097s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10876,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:42.118297 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=5.165500
I20260812 06:18:42.203368 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.085s	user 0.016s	sys 0.003s Metrics: {"bytes_written":7302546,"delete_count":0,"lbm_write_time_us":8066,"lbm_writes_lt_1ms":181,"mutex_wait_us":211,"reinsert_count":0,"update_count":890}
I20260812 06:18:42.204250 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=4.173312
I20260812 06:18:42.222893 11960 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.931s	user 1.745s	sys 0.178s
I20260812 06:18:42.306643 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.102s	user 0.009s	sys 0.012s Metrics: {"bytes_written":5415445,"delete_count":0,"lbm_write_time_us":8300,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:18:42.307559 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c): perf score=2.188937
I20260812 06:18:42.406688 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushDeltaMemStoresOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.099s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":450}
I20260812 06:18:42.407321 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling FlushMRSOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:42.513748 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: FlushMRSOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.106s	user 0.022s	sys 0.008s Metrics: {"bytes_written":1398558,"cfile_init":1,"dirs.queue_time_us":222,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1802,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":34,"thread_start_us":90,"threads_started":1}
I20260812 06:18:42.514549 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling LogGCOp(c169e2d3653f4958a3d287062399309c): free 124710577 bytes of WAL
I20260812 06:18:42.514819 12406 log_reader.cc:385] T c169e2d3653f4958a3d287062399309c: removed 12 log segments from log reader
I20260812 06:18:42.514868 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000028 (ops 136-140)
I20260812 06:18:42.514910 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000029 (ops 141-145)
I20260812 06:18:42.514987 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000030 (ops 146-150)
I20260812 06:18:42.515038 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000031 (ops 151-155)
I20260812 06:18:42.515060 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000032 (ops 156-160)
I20260812 06:18:42.515113 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000033 (ops 161-165)
I20260812 06:18:42.515146 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000034 (ops 166-170)
I20260812 06:18:42.515168 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000035 (ops 171-175)
I20260812 06:18:42.515208 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000036 (ops 176-180)
I20260812 06:18:42.515239 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000037 (ops 181-185)
I20260812 06:18:42.515290 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000038 (ops 186-190)
I20260812 06:18:42.515321 12406 log.cc:1079] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: Deleting log segment in path: /tmp/dist-test-taskb266Am/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511635187-11960-0/minicluster-data/ts-0-root/wals/c169e2d3653f4958a3d287062399309c/wal-000000039 (ops 191-195)
I20260812 06:18:42.538616 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: LogGCOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.024s	user 0.001s	sys 0.021s Metrics: {}
I20260812 06:18:42.539083 12492 maintenance_manager.cc:419] P 929bcd90b2a14cd283e34eec908cda8f: Scheduling MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c): perf score=1.000000
I20260812 06:18:42.559892 11960 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.336s	user 0.001s	sys 0.000s
I20260812 06:18:42.560686 11960 tablet_server.cc:179] TabletServer@127.11.174.1:0 shutting down...
I20260812 06:18:43.321702 12406 maintenance_manager.cc:643] P 929bcd90b2a14cd283e34eec908cda8f: MajorDeltaCompactionOp(c169e2d3653f4958a3d287062399309c) complete. Timing: real 0.782s	user 0.448s	sys 0.264s Metrics: {"cfile_cache_hit":2121,"cfile_cache_hit_bytes":90016391,"cfile_cache_miss":1243,"cfile_cache_miss_bytes":50406877,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":15,"delta_iterators_relevant":15,"dirs.queue_time_us":1154,"lbm_read_time_us":21355,"lbm_reads_lt_1ms":1259,"lbm_write_time_us":140734,"lbm_writes_lt_1ms":3365,"mutex_wait_us":62,"peak_mem_usage":412879965,"reinsert_count":0,"thread_start_us":354,"threads_started":6,"update_count":16595}
I20260812 06:18:43.322402 11960 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:43.322692 11960 tablet_replica.cc:333] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f: stopping tablet replica
I20260812 06:18:43.322821 11960 raft_consensus.cc:2243] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:43.323021 11960 raft_consensus.cc:2272] T c169e2d3653f4958a3d287062399309c P 929bcd90b2a14cd283e34eec908cda8f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:43.336879 11960 tablet_server.cc:196] TabletServer@127.11.174.1:0 shutdown complete.
I20260812 06:18:44.251554 11960 master.cc:562] Master@127.11.174.62:40397 shutting down...
I20260812 06:18:44.254487 11960 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.254724 11960 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.254787 11960 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6452eb2f98bb431bb25dfe422400f0dc: stopping tablet replica
I20260812 06:18:44.267357 11960 master.cc:584] Master@127.11.174.62:40397 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7275 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12699 ms total)

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