[==========] 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:51.680124 11309 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.11.126:39687
I20260812 06:18:51.681185 11309 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:51.681778 11309 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:51.688277 11317 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:51.688267 11315 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:51.688262 11309 server_base.cc:1061] running on GCE node
W20260812 06:18:51.688692 11314 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:51.689213 11309 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:51.689339 11309 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:51.689399 11309 hybrid_clock.cc:648] HybridClock initialized: now 1786515531689396 us; error 0 us; skew 500 ppm
I20260812 06:18:51.691268 11309 webserver.cc:533] Webserver started at http://127.11.11.126:34513/ using document root <none> and password file <none>
I20260812 06:18:51.691833 11309 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:51.691918 11309 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:51.692175 11309 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:51.693920 11309 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/master-0-root/instance:
uuid: "735d29f53cb6467480beebde469721f8"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-8n49"
I20260812 06:18:51.697548 11309 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:18:51.699770 11322 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:51.701050 11309 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:51.701193 11309 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/master-0-root
uuid: "735d29f53cb6467480beebde469721f8"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-8n49"
I20260812 06:18:51.701308 11309 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-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:51.715318 11309 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:51.715984 11309 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:51.716167 11309 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:51.723881 11381 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.11.126:39687 every 8 connection(s)
I20260812 06:18:51.723860 11309 rpc_server.cc:307] RPC server started. Bound to: 127.11.11.126:39687
I20260812 06:18:51.726262 11382 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:51.731833 11382 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: Bootstrap starting.
I20260812 06:18:51.734323 11382 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:51.735289 11382 log.cc:826] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:51.737206 11382 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: No bootstrap required, opened a new log
I20260812 06:18:51.740150 11382 raft_consensus.cc:359] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "735d29f53cb6467480beebde469721f8" member_type: VOTER }
I20260812 06:18:51.740338 11382 raft_consensus.cc:385] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:51.740382 11382 raft_consensus.cc:740] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 735d29f53cb6467480beebde469721f8, State: Initialized, Role: FOLLOWER
I20260812 06:18:51.741135 11382 consensus_queue.cc:260] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [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: "735d29f53cb6467480beebde469721f8" member_type: VOTER }
I20260812 06:18:51.741288 11382 raft_consensus.cc:399] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:51.741405 11382 raft_consensus.cc:493] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:51.741559 11382 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:51.742417 11382 raft_consensus.cc:515] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "735d29f53cb6467480beebde469721f8" member_type: VOTER }
I20260812 06:18:51.743078 11382 leader_election.cc:304] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [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: 735d29f53cb6467480beebde469721f8; no voters: 
I20260812 06:18:51.743463 11382 leader_election.cc:290] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:51.743635 11385 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:51.743880 11385 raft_consensus.cc:697] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 1 LEADER]: Becoming Leader. State: Replica: 735d29f53cb6467480beebde469721f8, State: Running, Role: LEADER
I20260812 06:18:51.744316 11385 consensus_queue.cc:237] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [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: "735d29f53cb6467480beebde469721f8" member_type: VOTER }
I20260812 06:18:51.744589 11382 sys_catalog.cc:565] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:51.746376 11386 sys_catalog.cc:455] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "735d29f53cb6467480beebde469721f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "735d29f53cb6467480beebde469721f8" member_type: VOTER } }
I20260812 06:18:51.746373 11387 sys_catalog.cc:455] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 735d29f53cb6467480beebde469721f8. Latest consensus state: current_term: 1 leader_uuid: "735d29f53cb6467480beebde469721f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "735d29f53cb6467480beebde469721f8" member_type: VOTER } }
I20260812 06:18:51.746564 11386 sys_catalog.cc:458] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:51.746564 11387 sys_catalog.cc:458] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:51.746968 11399 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:51.747062 11309 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:51.749577 11399 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:51.754364 11399 catalog_manager.cc:1383] Generated new cluster ID: 9d4a61a222994636b29008d782912edf
I20260812 06:18:51.754455 11399 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:51.775926 11399 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:51.776830 11399 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:51.790180 11399 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: Generated new TSK 0
I20260812 06:18:51.791038 11399 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:51.812045 11309 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:51.814960 11408 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:51.814930 11411 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:51.815109 11409 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:51.815303 11309 server_base.cc:1061] running on GCE node
I20260812 06:18:51.815533 11309 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:51.815583 11309 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:51.815608 11309 hybrid_clock.cc:648] HybridClock initialized: now 1786515531815607 us; error 0 us; skew 500 ppm
I20260812 06:18:51.816643 11309 webserver.cc:533] Webserver started at http://127.11.11.65:35189/ using document root <none> and password file <none>
I20260812 06:18:51.816823 11309 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:51.816893 11309 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:51.816974 11309 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:51.817364 11309 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/instance:
uuid: "86dfce92f4e2464b91eec5ab4b76ca12"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-8n49"
I20260812 06:18:51.818974 11309 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:51.820065 11416 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:51.820335 11309 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:51.820428 11309 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root
uuid: "86dfce92f4e2464b91eec5ab4b76ca12"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-8n49"
I20260812 06:18:51.820508 11309 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-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:51.830982 11309 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:51.831451 11309 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:51.832154 11309 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:51.833223 11309 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:51.833276 11309 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:51.833317 11309 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:51.833364 11309 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:51.840449 11309 rpc_server.cc:307] RPC server started. Bound to: 127.11.11.65:39923
I20260812 06:18:51.840472 11487 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.11.65:39923 every 8 connection(s)
I20260812 06:18:51.850715 11488 heartbeater.cc:344] Connected to a master server at 127.11.11.126:39687
I20260812 06:18:51.850962 11488 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:51.851424 11488 heartbeater.cc:507] Master 127.11.11.126:39687 requested a full tablet report, sending...
I20260812 06:18:51.852952 11339 ts_manager.cc:194] Registered new tserver with Master: 86dfce92f4e2464b91eec5ab4b76ca12 (127.11.11.65:39923)
I20260812 06:18:51.853701 11309 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012561472s
I20260812 06:18:51.854455 11339 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58294
I20260812 06:18:51.864498 11339 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58304:
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:51.879990 11445 tablet_service.cc:1511] Processing CreateTablet for tablet c4afee337d37429b810f8aef78b8ec7f (DEFAULT_TABLE table=heavy-update-compaction-test [id=f5dd75d502724aa48020a909561886f2]), partition=
I20260812 06:18:51.880481 11445 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c4afee337d37429b810f8aef78b8ec7f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:51.883514 11502 tablet_bootstrap.cc:492] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Bootstrap starting.
I20260812 06:18:51.884472 11502 tablet_bootstrap.cc:654] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:51.885713 11502 tablet_bootstrap.cc:492] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: No bootstrap required, opened a new log
I20260812 06:18:51.885823 11502 ts_tablet_manager.cc:1403] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:51.886303 11502 raft_consensus.cc:359] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "86dfce92f4e2464b91eec5ab4b76ca12" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 39923 } }
I20260812 06:18:51.886405 11502 raft_consensus.cc:385] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:51.886430 11502 raft_consensus.cc:740] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 86dfce92f4e2464b91eec5ab4b76ca12, State: Initialized, Role: FOLLOWER
I20260812 06:18:51.886610 11502 consensus_queue.cc:260] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [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: "86dfce92f4e2464b91eec5ab4b76ca12" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 39923 } }
I20260812 06:18:51.886751 11502 raft_consensus.cc:399] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:51.886845 11502 raft_consensus.cc:493] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:51.886911 11502 raft_consensus.cc:3060] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:51.887815 11502 raft_consensus.cc:515] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "86dfce92f4e2464b91eec5ab4b76ca12" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 39923 } }
I20260812 06:18:51.887948 11502 leader_election.cc:304] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [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: 86dfce92f4e2464b91eec5ab4b76ca12; no voters: 
I20260812 06:18:51.888159 11502 leader_election.cc:290] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:51.888299 11504 raft_consensus.cc:2804] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:51.888527 11502 ts_tablet_manager.cc:1434] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:51.888989 11504 raft_consensus.cc:697] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 1 LEADER]: Becoming Leader. State: Replica: 86dfce92f4e2464b91eec5ab4b76ca12, State: Running, Role: LEADER
I20260812 06:18:51.889232 11504 consensus_queue.cc:237] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [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: "86dfce92f4e2464b91eec5ab4b76ca12" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 39923 } }
I20260812 06:18:51.891093 11488 heartbeater.cc:499] Master 127.11.11.126:39687 was elected leader, sending a full tablet report...
I20260812 06:18:51.894029 11339 catalog_manager.cc:5719] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 reported cstate change: term changed from 0 to 1, leader changed from <none> to 86dfce92f4e2464b91eec5ab4b76ca12 (127.11.11.65). New cstate: current_term: 1 leader_uuid: "86dfce92f4e2464b91eec5ab4b76ca12" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "86dfce92f4e2464b91eec5ab4b76ca12" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 39923 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:51.960705 11309 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.019s	sys 0.008s
I20260812 06:18:52.091647 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f): perf score=15.086190
I20260812 06:18:52.249935 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.158s	user 0.146s	sys 0.008s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":228,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":935,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36148,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":123,"threads_started":1,"update_count":1500}
I20260812 06:18:52.251087 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling LogGCOp(c4afee337d37429b810f8aef78b8ec7f): free 20290830 bytes of WAL
I20260812 06:18:52.251427 11421 log_reader.cc:385] T c4afee337d37429b810f8aef78b8ec7f: removed 2 log segments from log reader
I20260812 06:18:52.251518 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000001 (ops 1-6)
I20260812 06:18:52.251611 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000002 (ops 7-10)
I20260812 06:18:52.255656 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: LogGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:52.256016 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f): 12308958 bytes on disk
I20260812 06:18:52.256682 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.257136 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:52.271088 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.271763 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:52.392513 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.121s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":8328,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23381,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":347,"threads_started":5,"update_count":2000}
I20260812 06:18:52.393172 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:52.438903 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.046s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14415,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.439404 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:52.450006 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.450455 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:52.570667 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.120s	user 0.108s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":8617,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21624,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":95616,"update_count":2000}
I20260812 06:18:52.571205 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:52.615687 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.044s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14562,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.616276 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:52.630419 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5650,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.630865 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:52.757050 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.126s	user 0.106s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":8797,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23842,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":101120,"update_count":2000}
I20260812 06:18:52.758005 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:52.809799 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.052s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17294,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.810413 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:52.822214 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.822728 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:52.967592 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.145s	user 0.100s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1526,"lbm_read_time_us":11300,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21986,"lbm_writes_lt_1ms":443,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:52.968146 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:53.013038 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.045s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.013597 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:53.024811 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.025568 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:53.151885 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.126s	user 0.090s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":408,"lbm_read_time_us":9631,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24714,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:18:53.152422 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:53.201946 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.049s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16511,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.202430 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:53.213181 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.213886 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:53.341221 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.127s	user 0.094s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":9458,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24340,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.341892 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:53.399492 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.057s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.400024 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:53.410717 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.411158 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:53.441136 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":343,"dirs.run_wall_time_us":1557,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1345,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:53.441967 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:53.590654 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.148s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":9471,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24005,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:53.591305 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling LogGCOp(c4afee337d37429b810f8aef78b8ec7f): free 112692313 bytes of WAL
I20260812 06:18:53.591552 11421 log_reader.cc:385] T c4afee337d37429b810f8aef78b8ec7f: removed 11 log segments from log reader
I20260812 06:18:53.591611 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000003 (ops 11-15)
I20260812 06:18:53.591673 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000004 (ops 16-20)
I20260812 06:18:53.591715 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000005 (ops 21-25)
I20260812 06:18:53.591758 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000006 (ops 26-30)
I20260812 06:18:53.591801 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000007 (ops 31-35)
I20260812 06:18:53.591845 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000008 (ops 36-40)
I20260812 06:18:53.591888 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000009 (ops 41-45)
I20260812 06:18:53.591931 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000010 (ops 46-50)
I20260812 06:18:53.591974 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000011 (ops 51-55)
I20260812 06:18:53.592023 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000012 (ops 56-60)
I20260812 06:18:53.592057 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000013 (ops 61-65)
I20260812 06:18:53.620150 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: LogGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:53.620678 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f): 448 bytes on disk
I20260812 06:18:53.621196 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.621728 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:53.671797 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.050s	user 0.042s	sys 0.005s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21947,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.672338 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:53.684324 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.684834 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:53.859938 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.175s	user 0.125s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":612,"lbm_read_time_us":11349,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27068,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:18:53.860500 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:53.913553 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.053s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.914036 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:53.926055 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.926656 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.077524 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.151s	user 0.109s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":10108,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30960,"lbm_writes_lt_1ms":543,"mutex_wait_us":5,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:54.078215 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:54.129096 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.051s	user 0.035s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18400,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.129669 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:54.141577 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.142189 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.298915 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.157s	user 0.127s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":10466,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33875,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:54.299584 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=11.118625
I20260812 06:18:54.328966 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.029s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12907,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:54.329450 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:54.341879 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.342492 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.468166 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.125s	user 0.097s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":7541,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25354,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":64896,"update_count":2000}
I20260812 06:18:54.468907 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:54.519662 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.051s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15771,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.520238 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:54.530821 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.531304 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.686725 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.155s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":10120,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25608,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.687502 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:54.734227 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.047s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15197,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.734679 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:54.746399 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.747088 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.875640 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.128s	user 0.088s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":9836,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23832,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:18:54.876298 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:54.923823 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.047s	user 0.011s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14993,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.924463 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:54.940294 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.940867 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:54.970248 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1256,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1563,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:54.971047 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling LogGCOp(c4afee337d37429b810f8aef78b8ec7f): free 120553382 bytes of WAL
I20260812 06:18:54.971308 11421 log_reader.cc:385] T c4afee337d37429b810f8aef78b8ec7f: removed 12 log segments from log reader
I20260812 06:18:54.971367 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000014 (ops 66-70)
I20260812 06:18:54.971410 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000015 (ops 71-75)
I20260812 06:18:54.971434 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000016 (ops 76-80)
I20260812 06:18:54.971508 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000017 (ops 81-84)
I20260812 06:18:54.971560 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000018 (ops 85-89)
I20260812 06:18:54.971599 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000019 (ops 90-94)
I20260812 06:18:54.971622 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000020 (ops 95-99)
I20260812 06:18:54.971644 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000021 (ops 100-104)
I20260812 06:18:54.971665 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000022 (ops 105-108)
I20260812 06:18:54.971688 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000023 (ops 109-113)
I20260812 06:18:54.971709 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000024 (ops 114-118)
I20260812 06:18:54.971730 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000025 (ops 119-123)
I20260812 06:18:54.998765 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: LogGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:54.999226 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f): 482 bytes on disk
I20260812 06:18:54.999648 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.000190 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:55.025992 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.026s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.026484 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:55.041517 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.042128 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:55.232620 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.190s	user 0.134s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836373,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1059,"lbm_read_time_us":11416,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38931,"lbm_writes_lt_1ms":643,"mutex_wait_us":511,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:18:55.233399 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:55.288688 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.055s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25327,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.289158 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:55.300150 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.300954 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:55.469187 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.168s	user 0.128s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1118,"lbm_read_time_us":10635,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31163,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:55.469937 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:55.529372 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.059s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23140,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.529934 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:55.541194 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.541725 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:55.718452 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.177s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":679,"lbm_read_time_us":12132,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27438,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":109440,"update_count":2500}
I20260812 06:18:55.719177 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:55.782594 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.063s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23140,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.783350 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:55.794560 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.795362 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:55.972931 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.177s	user 0.116s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":405,"lbm_read_time_us":12719,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29250,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:55.973495 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=11.118625
I20260812 06:18:56.022241 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.049s	user 0.025s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17485,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:56.022795 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.047412 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.024s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.047885 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.058579 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.059113 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:56.242226 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.183s	user 0.115s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":683,"lbm_read_time_us":12205,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30583,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:56.242763 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:56.305334 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.062s	user 0.039s	sys 0.017s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.305912 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.316728 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.317179 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:56.479065 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.162s	user 0.102s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":144,"lbm_read_time_us":11804,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26756,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:18:56.479839 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=10.126437
I20260812 06:18:56.523648 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.044s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17599,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:56.524183 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.534554 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.535068 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:56.576360 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushMRSOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.041s	user 0.030s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1759,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1420,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:56.577235 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling LogGCOp(c4afee337d37429b810f8aef78b8ec7f): free 133024675 bytes of WAL
I20260812 06:18:56.577523 11421 log_reader.cc:385] T c4afee337d37429b810f8aef78b8ec7f: removed 13 log segments from log reader
I20260812 06:18:56.577586 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000026 (ops 124-128)
I20260812 06:18:56.577626 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000027 (ops 129-133)
I20260812 06:18:56.577663 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000028 (ops 134-138)
I20260812 06:18:56.577687 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000029 (ops 139-142)
I20260812 06:18:56.577715 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000030 (ops 143-147)
I20260812 06:18:56.577740 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000031 (ops 148-152)
I20260812 06:18:56.577766 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000032 (ops 153-157)
I20260812 06:18:56.577800 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000033 (ops 158-162)
I20260812 06:18:56.577833 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000034 (ops 163-167)
I20260812 06:18:56.577862 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000035 (ops 168-172)
I20260812 06:18:56.577890 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000036 (ops 173-177)
I20260812 06:18:56.577916 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000037 (ops 178-182)
I20260812 06:18:56.577950 11421 log.cc:1079] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/c4afee337d37429b810f8aef78b8ec7f/wal-000000038 (ops 183-187)
I20260812 06:18:56.607016 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: LogGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:56.607613 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f): 482 bytes on disk
I20260812 06:18:56.608151 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: UndoDeltaBlockGCOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:56.608837 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.625707 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.017s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.626150 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:56.797034 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.171s	user 0.123s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733842,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":554,"lbm_read_time_us":10621,"lbm_reads_lt_1ms":565,"lbm_write_time_us":27732,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"thread_start_us":84,"threads_started":1,"update_count":2500}
I20260812 06:18:56.797771 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=14.095187
I20260812 06:18:56.859407 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.061s	user 0.022s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":31566,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.859954 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=3.181125
I20260812 06:18:56.889766 11309 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.923s	user 1.848s	sys 0.130s
I20260812 06:18:56.890544 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.030s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4307783,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:18:56.891022 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f): perf score=2.188937
I20260812 06:18:56.902539 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: FlushDeltaMemStoresOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4853,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:56.902979 11489 maintenance_manager.cc:419] P 86dfce92f4e2464b91eec5ab4b76ca12: Scheduling MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f): perf score=1.000000
I20260812 06:18:56.974043 11309 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.002s	sys 0.000s
I20260812 06:18:56.974808 11309 tablet_server.cc:179] TabletServer@127.11.11.65:0 shutting down...
I20260812 06:18:57.058853 11421 maintenance_manager.cc:643] P 86dfce92f4e2464b91eec5ab4b76ca12: MajorDeltaCompactionOp(c4afee337d37429b810f8aef78b8ec7f) complete. Timing: real 0.156s	user 0.086s	sys 0.069s Metrics: {"cfile_cache_hit":183,"cfile_cache_hit_bytes":7429858,"cfile_cache_miss":450,"cfile_cache_miss_bytes":21406395,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":816,"lbm_read_time_us":10744,"lbm_reads_lt_1ms":482,"lbm_write_time_us":28591,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":109312,"update_count":3000}
I20260812 06:18:57.059628 11309 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:57.060088 11309 tablet_replica.cc:333] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12: stopping tablet replica
I20260812 06:18:57.060273 11309 raft_consensus.cc:2243] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:57.060447 11309 raft_consensus.cc:2272] T c4afee337d37429b810f8aef78b8ec7f P 86dfce92f4e2464b91eec5ab4b76ca12 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:57.075475 11309 tablet_server.cc:196] TabletServer@127.11.11.65:0 shutdown complete.
I20260812 06:18:57.112263 11309 master.cc:562] Master@127.11.11.126:39687 shutting down...
I20260812 06:18:57.116271 11309 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:57.116495 11309 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:57.116613 11309 tablet_replica.cc:333] T 00000000000000000000000000000000 P 735d29f53cb6467480beebde469721f8: stopping tablet replica
I20260812 06:18:57.129097 11309 master.cc:584] Master@127.11.11.126:39687 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5545 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:57.238601 11309 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.11.126:35733
I20260812 06:18:57.239055 11309 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:57.241227 11523 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:57.241268 11522 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:57.241339 11309 server_base.cc:1061] running on GCE node
W20260812 06:18:57.241334 11525 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:57.241637 11309 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:57.241684 11309 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:57.241699 11309 hybrid_clock.cc:648] HybridClock initialized: now 1786515537241700 us; error 0 us; skew 500 ppm
I20260812 06:18:57.242518 11309 webserver.cc:533] Webserver started at http://127.11.11.126:45945/ using document root <none> and password file <none>
I20260812 06:18:57.242652 11309 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:57.242694 11309 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:57.242746 11309 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:57.243125 11309 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/master-0-root/instance:
uuid: "52584514198f43b387e60ba1aaf385fc"
format_stamp: "Formatted at 2026-08-12 06:18:57 on dist-test-slave-8n49"
I20260812 06:18:57.244719 11309 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:57.245750 11531 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:57.246064 11309 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:57.246133 11309 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/master-0-root
uuid: "52584514198f43b387e60ba1aaf385fc"
format_stamp: "Formatted at 2026-08-12 06:18:57 on dist-test-slave-8n49"
I20260812 06:18:57.246228 11309 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-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:57.267689 11309 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:57.268144 11309 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:57.272616 11309 rpc_server.cc:307] RPC server started. Bound to: 127.11.11.126:35733
I20260812 06:18:57.275789 11593 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.11.126:35733 every 8 connection(s)
I20260812 06:18:57.276230 11594 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:57.278054 11594 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc: Bootstrap starting.
I20260812 06:18:57.278851 11594 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:57.279939 11594 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc: No bootstrap required, opened a new log
I20260812 06:18:57.280354 11594 raft_consensus.cc:359] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER }
I20260812 06:18:57.280452 11594 raft_consensus.cc:385] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:57.280475 11594 raft_consensus.cc:740] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 52584514198f43b387e60ba1aaf385fc, State: Initialized, Role: FOLLOWER
I20260812 06:18:57.280645 11594 consensus_queue.cc:260] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [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: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER }
I20260812 06:18:57.280722 11594 raft_consensus.cc:399] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:57.280781 11594 raft_consensus.cc:493] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:57.280864 11594 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:57.281582 11594 raft_consensus.cc:515] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER }
I20260812 06:18:57.281716 11594 leader_election.cc:304] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [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: 52584514198f43b387e60ba1aaf385fc; no voters: 
I20260812 06:18:57.281942 11594 leader_election.cc:290] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:57.282091 11597 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:57.282321 11597 raft_consensus.cc:697] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 1 LEADER]: Becoming Leader. State: Replica: 52584514198f43b387e60ba1aaf385fc, State: Running, Role: LEADER
I20260812 06:18:57.282495 11597 consensus_queue.cc:237] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [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: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER }
I20260812 06:18:57.282606 11594 sys_catalog.cc:565] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:57.282933 11598 sys_catalog.cc:455] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "52584514198f43b387e60ba1aaf385fc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER } }
I20260812 06:18:57.283041 11598 sys_catalog.cc:458] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:57.283186 11599 sys_catalog.cc:455] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 52584514198f43b387e60ba1aaf385fc. Latest consensus state: current_term: 1 leader_uuid: "52584514198f43b387e60ba1aaf385fc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52584514198f43b387e60ba1aaf385fc" member_type: VOTER } }
I20260812 06:18:57.283272 11599 sys_catalog.cc:458] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:57.283803 11601 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:57.284464 11601 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:57.284655 11309 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:57.286334 11601 catalog_manager.cc:1383] Generated new cluster ID: 9a5f38b7658f48439cc320968355f6ae
I20260812 06:18:57.286397 11601 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:57.300369 11601 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:57.301081 11601 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:57.305831 11601 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc: Generated new TSK 0
I20260812 06:18:57.306043 11601 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:57.317343 11309 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:57.319623 11616 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:57.319633 11619 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:57.319782 11309 server_base.cc:1061] running on GCE node
W20260812 06:18:57.319651 11617 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:57.320148 11309 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:57.320194 11309 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:57.320209 11309 hybrid_clock.cc:648] HybridClock initialized: now 1786515537320209 us; error 0 us; skew 500 ppm
I20260812 06:18:57.321089 11309 webserver.cc:533] Webserver started at http://127.11.11.65:42779/ using document root <none> and password file <none>
I20260812 06:18:57.321233 11309 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:57.321277 11309 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:57.321334 11309 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:57.321705 11309 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/instance:
uuid: "a83d060712f4463b95543e0635dd8fae"
format_stamp: "Formatted at 2026-08-12 06:18:57 on dist-test-slave-8n49"
I20260812 06:18:57.323273 11309 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:57.324266 11625 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:57.324656 11309 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:57.324731 11309 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root
uuid: "a83d060712f4463b95543e0635dd8fae"
format_stamp: "Formatted at 2026-08-12 06:18:57 on dist-test-slave-8n49"
I20260812 06:18:57.324823 11309 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-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:57.331331 11309 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:57.331771 11309 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:57.332094 11309 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:57.332651 11309 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:57.332708 11309 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:57.332777 11309 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:57.332823 11309 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:57.337031 11309 rpc_server.cc:307] RPC server started. Bound to: 127.11.11.65:41373
I20260812 06:18:57.337107 11699 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.11.65:41373 every 8 connection(s)
I20260812 06:18:57.346302 11700 heartbeater.cc:344] Connected to a master server at 127.11.11.126:35733
I20260812 06:18:57.346424 11700 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:57.346700 11700 heartbeater.cc:507] Master 127.11.11.126:35733 requested a full tablet report, sending...
I20260812 06:18:57.347360 11553 ts_manager.cc:194] Registered new tserver with Master: a83d060712f4463b95543e0635dd8fae (127.11.11.65:41373)
I20260812 06:18:57.347592 11309 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010077231s
I20260812 06:18:57.348399 11553 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35570
I20260812 06:18:57.355581 11553 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35580:
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:57.364543 11655 tablet_service.cc:1511] Processing CreateTablet for tablet dc63961e5d804fc2975ba49091694ba6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=2653be9837964338a477b29b982da262]), partition=
I20260812 06:18:57.364846 11655 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dc63961e5d804fc2975ba49091694ba6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:57.366691 11713 tablet_bootstrap.cc:492] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Bootstrap starting.
I20260812 06:18:57.367579 11713 tablet_bootstrap.cc:654] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:57.368762 11713 tablet_bootstrap.cc:492] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: No bootstrap required, opened a new log
I20260812 06:18:57.368886 11713 ts_tablet_manager.cc:1403] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:57.369300 11713 raft_consensus.cc:359] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83d060712f4463b95543e0635dd8fae" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 41373 } }
I20260812 06:18:57.369407 11713 raft_consensus.cc:385] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:57.369467 11713 raft_consensus.cc:740] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a83d060712f4463b95543e0635dd8fae, State: Initialized, Role: FOLLOWER
I20260812 06:18:57.369607 11713 consensus_queue.cc:260] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [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: "a83d060712f4463b95543e0635dd8fae" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 41373 } }
I20260812 06:18:57.369714 11713 raft_consensus.cc:399] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:57.369797 11713 raft_consensus.cc:493] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:57.369861 11713 raft_consensus.cc:3060] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:57.370992 11713 raft_consensus.cc:515] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83d060712f4463b95543e0635dd8fae" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 41373 } }
I20260812 06:18:57.371176 11713 leader_election.cc:304] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [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: a83d060712f4463b95543e0635dd8fae; no voters: 
I20260812 06:18:57.371384 11713 leader_election.cc:290] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:57.371495 11715 raft_consensus.cc:2804] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:57.371717 11715 raft_consensus.cc:697] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 1 LEADER]: Becoming Leader. State: Replica: a83d060712f4463b95543e0635dd8fae, State: Running, Role: LEADER
I20260812 06:18:57.371759 11713 ts_tablet_manager.cc:1434] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:57.372066 11715 consensus_queue.cc:237] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [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: "a83d060712f4463b95543e0635dd8fae" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 41373 } }
I20260812 06:18:57.372228 11700 heartbeater.cc:499] Master 127.11.11.126:35733 was elected leader, sending a full tablet report...
I20260812 06:18:57.373499 11553 catalog_manager.cc:5719] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae reported cstate change: term changed from 0 to 1, leader changed from <none> to a83d060712f4463b95543e0635dd8fae (127.11.11.65). New cstate: current_term: 1 leader_uuid: "a83d060712f4463b95543e0635dd8fae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83d060712f4463b95543e0635dd8fae" member_type: VOTER last_known_addr { host: "127.11.11.65" port: 41373 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:57.430704 11309 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.008s
I20260812 06:18:57.587976 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushMRSOp(dc63961e5d804fc2975ba49091694ba6): perf score=19.054940
I20260812 06:18:57.750262 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushMRSOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.162s	user 0.109s	sys 0.051s Metrics: {"bytes_written":13086955,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1113,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39263,"lbm_writes_lt_1ms":786,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2560,"update_count":1595}
I20260812 06:18:57.750972 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling LogGCOp(dc63961e5d804fc2975ba49091694ba6): free 20743880 bytes of WAL
I20260812 06:18:57.751252 11631 log_reader.cc:385] T dc63961e5d804fc2975ba49091694ba6: removed 2 log segments from log reader
I20260812 06:18:57.751298 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000001 (ops 1-6)
I20260812 06:18:57.751328 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000002 (ops 7-11)
I20260812 06:18:57.755882 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: LogGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:57.756247 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6): 16821647 bytes on disk
I20260812 06:18:57.756733 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.757135 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:57.768961 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3979588,"delete_count":0,"lbm_write_time_us":4586,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:57.769483 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.196750
I20260812 06:18:57.777607 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":2838,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:18:57.778345 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:57.975389 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.197s	user 0.133s	sys 0.064s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405543,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":523,"lbm_read_time_us":13016,"lbm_reads_lt_1ms":559,"lbm_write_time_us":32547,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":378,"threads_started":5,"update_count":2450}
I20260812 06:18:57.976143 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:18:58.024003 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.048s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.024540 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:58.044193 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.019s	user 0.001s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.044902 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:58.234127 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.189s	user 0.121s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":691,"lbm_read_time_us":11779,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28724,"lbm_writes_lt_1ms":543,"mutex_wait_us":179,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:18:58.234843 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:18:58.284368 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.049s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21178,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.285045 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:58.299360 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.300082 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:58.492930 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.193s	user 0.144s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":744,"lbm_read_time_us":11775,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29097,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:18:58.493448 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:18:58.546579 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.053s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21135,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.547065 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:58.557974 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.558597 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:58.719229 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.160s	user 0.111s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":995,"lbm_read_time_us":10115,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33200,"lbm_writes_lt_1ms":543,"mutex_wait_us":376,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":2500}
I20260812 06:18:58.719846 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=11.118625
I20260812 06:18:58.763517 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.043s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19041,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:58.764226 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:58.788031 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.788513 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:58.799181 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.799639 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:58.952775 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.153s	user 0.124s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":670,"lbm_read_time_us":10205,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31876,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:18:58.956893 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=10.126437
I20260812 06:18:59.003836 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.047s	user 0.038s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.004343 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.027536 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.023s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.028023 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.038750 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.039212 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushMRSOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:59.069895 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushMRSOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1429,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1819,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:59.070549 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling LogGCOp(dc63961e5d804fc2975ba49091694ba6): free 121006437 bytes of WAL
I20260812 06:18:59.070773 11631 log_reader.cc:385] T dc63961e5d804fc2975ba49091694ba6: removed 12 log segments from log reader
I20260812 06:18:59.070816 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000003 (ops 12-16)
I20260812 06:18:59.070868 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000004 (ops 17-21)
I20260812 06:18:59.070912 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000005 (ops 22-26)
I20260812 06:18:59.070956 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000006 (ops 27-31)
I20260812 06:18:59.070996 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000007 (ops 32-36)
I20260812 06:18:59.071022 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000008 (ops 37-41)
I20260812 06:18:59.071061 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000009 (ops 42-46)
I20260812 06:18:59.071105 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000010 (ops 47-51)
I20260812 06:18:59.071146 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000011 (ops 52-56)
I20260812 06:18:59.071192 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000012 (ops 57-60)
I20260812 06:18:59.071236 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000013 (ops 61-65)
I20260812 06:18:59.071275 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000014 (ops 66-70)
I20260812 06:18:59.096473 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: LogGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:59.096962 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6): 461 bytes on disk
I20260812 06:18:59.097476 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:59.097959 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=3.181125
I20260812 06:18:59.109551 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:59.110036 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.119554 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3508,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:59.120134 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:59.369381 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.249s	user 0.166s	sys 0.064s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2727,"lbm_read_time_us":14757,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37478,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:18:59.370002 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=18.063937
I20260812 06:18:59.440447 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.070s	user 0.038s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26326,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:59.441104 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.460404 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.461046 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:59.653004 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.192s	user 0.150s	sys 0.041s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1614,"lbm_read_time_us":13893,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31513,"lbm_writes_lt_1ms":643,"mutex_wait_us":454,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":3000}
I20260812 06:18:59.653723 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:18:59.703661 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.050s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22332,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.704203 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.718951 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.719542 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:18:59.912372 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.193s	user 0.137s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":869,"lbm_read_time_us":13590,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30698,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:18:59.913643 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:18:59.975235 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.061s	user 0.027s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20499,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.975942 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:18:59.986807 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.987278 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:00.157521 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.170s	user 0.113s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":13105,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27037,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:19:00.158213 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:19:00.220463 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.062s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.221098 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:00.231877 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.232475 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:00.420171 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.187s	user 0.125s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":13082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32296,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25600,"update_count":2500}
I20260812 06:19:00.420840 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=11.118625
I20260812 06:19:00.461563 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.041s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17280,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:00.462213 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:00.485965 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.024s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:00.486397 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:00.505049 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.018s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3891,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.505573 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushMRSOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:00.541925 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushMRSOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.036s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":157,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1527,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:00.542611 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling LogGCOp(dc63961e5d804fc2975ba49091694ba6): free 115490125 bytes of WAL
I20260812 06:19:00.542809 11631 log_reader.cc:385] T dc63961e5d804fc2975ba49091694ba6: removed 11 log segments from log reader
I20260812 06:19:00.542858 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000015 (ops 71-75)
I20260812 06:19:00.542896 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000016 (ops 76-80)
I20260812 06:19:00.542925 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000017 (ops 81-85)
I20260812 06:19:00.542953 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000018 (ops 86-90)
I20260812 06:19:00.542984 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000019 (ops 91-94)
I20260812 06:19:00.543023 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000020 (ops 95-99)
I20260812 06:19:00.543057 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000021 (ops 100-104)
I20260812 06:19:00.543087 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000022 (ops 105-109)
I20260812 06:19:00.543113 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000023 (ops 110-114)
I20260812 06:19:00.543143 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000024 (ops 115-119)
I20260812 06:19:00.543169 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000025 (ops 120-124)
I20260812 06:19:00.570529 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: LogGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:00.570984 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6): 447 bytes on disk
I20260812 06:19:00.571426 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.572309 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:00.587042 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.587570 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:00.793541 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.206s	user 0.130s	sys 0.069s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918326,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1361,"lbm_read_time_us":12720,"lbm_reads_lt_1ms":666,"lbm_write_time_us":33635,"lbm_writes_lt_1ms":643,"mutex_wait_us":1095,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:00.794175 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=18.063937
I20260812 06:19:00.857950 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.064s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512325,"delete_count":0,"lbm_write_time_us":27728,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:00.858446 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:00.868996 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.869437 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:01.095817 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.226s	user 0.136s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"lbm_read_time_us":14161,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33124,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":3000}
I20260812 06:19:01.096725 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=18.063937
I20260812 06:19:01.164532 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.068s	user 0.038s	sys 0.021s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":28149,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:01.165242 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:01.177574 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.178304 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:01.411628 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.233s	user 0.154s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":965,"lbm_read_time_us":15697,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35448,"lbm_writes_lt_1ms":643,"mutex_wait_us":395,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":3000}
I20260812 06:19:01.412596 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:19:01.485421 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.073s	user 0.053s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28099,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.486088 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:01.505254 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.019s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.506187 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:01.788827 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.282s	user 0.192s	sys 0.089s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":19531,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40863,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:19:01.789759 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=23.024875
I20260812 06:19:01.872611 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.082s	user 0.065s	sys 0.013s Metrics: {"bytes_written":25024965,"delete_count":0,"lbm_write_time_us":36980,"lbm_writes_lt_1ms":613,"reinsert_count":0,"update_count":3050}
I20260812 06:19:01.873097 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=6.157687
I20260812 06:19:01.897588 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.024s	user 0.015s	sys 0.005s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8418,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:01.898180 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:02.123582 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.225s	user 0.151s	sys 0.071s Metrics: {"cfile_cache_miss":832,"cfile_cache_miss_bytes":37122918,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":15927,"lbm_reads_lt_1ms":864,"lbm_write_time_us":41671,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":4000}
I20260812 06:19:02.124266 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=18.063937
I20260812 06:19:02.191948 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.068s	user 0.024s	sys 0.040s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":31317,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.192528 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:02.203178 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.203647 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushMRSOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:02.236913 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushMRSOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.033s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1490,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1697,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:02.237721 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling LogGCOp(dc63961e5d804fc2975ba49091694ba6): free 133477682 bytes of WAL
I20260812 06:19:02.238006 11631 log_reader.cc:385] T dc63961e5d804fc2975ba49091694ba6: removed 13 log segments from log reader
I20260812 06:19:02.238070 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000026 (ops 125-129)
I20260812 06:19:02.238107 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000027 (ops 130-134)
I20260812 06:19:02.238129 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000028 (ops 135-139)
I20260812 06:19:02.238153 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000029 (ops 140-144)
I20260812 06:19:02.238179 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000030 (ops 145-149)
I20260812 06:19:02.238214 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000031 (ops 150-154)
I20260812 06:19:02.238235 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000032 (ops 155-159)
I20260812 06:19:02.238263 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000033 (ops 160-164)
I20260812 06:19:02.238289 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000034 (ops 165-169)
I20260812 06:19:02.238319 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000035 (ops 170-174)
I20260812 06:19:02.238353 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000036 (ops 175-179)
I20260812 06:19:02.238380 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000037 (ops 180-184)
I20260812 06:19:02.238408 11631 log.cc:1079] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: Deleting log segment in path: /tmp/dist-test-tasktA8WVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515531669405-11309-0/minicluster-data/ts-0-root/wals/dc63961e5d804fc2975ba49091694ba6/wal-000000038 (ops 185-189)
I20260812 06:19:02.270473 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: LogGCOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:02.271008 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6): 493 bytes on disk
I20260812 06:19:02.271536 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: UndoDeltaBlockGCOp(dc63961e5d804fc2975ba49091694ba6) 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:19:02.272161 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:02.294417 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.022s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6168,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.294907 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=2.188937
I20260812 06:19:02.309742 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.310307 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:02.521207 11309 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.090s	user 1.940s	sys 0.174s
I20260812 06:19:02.554903 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.244s	user 0.189s	sys 0.053s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17116,"lbm_reads_lt_1ms":870,"lbm_write_time_us":54831,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":27776,"update_count":4000}
I20260812 06:19:02.555483 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6): perf score=14.095187
I20260812 06:19:02.614251 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: FlushDeltaMemStoresOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.059s	user 0.045s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27799,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:02.614840 11701 maintenance_manager.cc:419] P a83d060712f4463b95543e0635dd8fae: Scheduling MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6): perf score=1.000000
I20260812 06:19:02.635154 11309 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.000s	sys 0.000s
I20260812 06:19:02.635663 11309 tablet_server.cc:179] TabletServer@127.11.11.65:0 shutting down...
I20260812 06:19:02.730173 11631 maintenance_manager.cc:643] P a83d060712f4463b95543e0635dd8fae: MajorDeltaCompactionOp(dc63961e5d804fc2975ba49091694ba6) complete. Timing: real 0.115s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":573,"lbm_read_time_us":9404,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23650,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":88576,"update_count":2000}
I20260812 06:19:02.730962 11309 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:02.731207 11309 tablet_replica.cc:333] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae: stopping tablet replica
I20260812 06:19:02.731370 11309 raft_consensus.cc:2243] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:02.731541 11309 raft_consensus.cc:2272] T dc63961e5d804fc2975ba49091694ba6 P a83d060712f4463b95543e0635dd8fae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:02.746663 11309 tablet_server.cc:196] TabletServer@127.11.11.65:0 shutdown complete.
I20260812 06:19:02.777971 11309 master.cc:562] Master@127.11.11.126:35733 shutting down...
I20260812 06:19:02.782612 11309 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:02.782828 11309 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:02.782917 11309 tablet_replica.cc:333] T 00000000000000000000000000000000 P 52584514198f43b387e60ba1aaf385fc: stopping tablet replica
I20260812 06:19:02.795504 11309 master.cc:584] Master@127.11.11.126:35733 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5655 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11202 ms total)

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