[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:54.502004 26522 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.230.190:44225
I20260812 06:19:54.503026 26522 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:54.503604 26522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.510366 26528 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.510380 26531 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.510423 26529 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.510437 26522 server_base.cc:1061] running on GCE node
I20260812 06:19:54.511158 26522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.511250 26522 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.511276 26522 hybrid_clock.cc:648] HybridClock initialized: now 1786515594511274 us; error 0 us; skew 500 ppm
I20260812 06:19:54.513175 26522 webserver.cc:533] Webserver started at http://127.25.230.190:33399/ using document root <none> and password file <none>
I20260812 06:19:54.513717 26522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.513773 26522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.513968 26522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.515666 26522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/master-0-root/instance:
uuid: "1b3f79f9896a4262a5ff57cf41214b1b"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-tm1g"
I20260812 06:19:54.519213 26522 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:54.521287 26537 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.522396 26522 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:54.522521 26522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/master-0-root
uuid: "1b3f79f9896a4262a5ff57cf41214b1b"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-tm1g"
I20260812 06:19:54.522646 26522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:54.558856 26522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.559675 26522 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:54.559897 26522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.569247 26522 rpc_server.cc:307] RPC server started. Bound to: 127.25.230.190:44225
I20260812 06:19:54.569255 26599 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.230.190:44225 every 8 connection(s)
I20260812 06:19:54.571805 26600 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.577548 26600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: Bootstrap starting.
I20260812 06:19:54.580360 26600 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.581374 26600 log.cc:826] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:54.583314 26600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: No bootstrap required, opened a new log
I20260812 06:19:54.586212 26600 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER }
I20260812 06:19:54.586403 26600 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.586493 26600 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1b3f79f9896a4262a5ff57cf41214b1b, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.587193 26600 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [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: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER }
I20260812 06:19:54.587369 26600 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.587440 26600 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.587611 26600 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.588449 26600 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER }
I20260812 06:19:54.588918 26600 leader_election.cc:304] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [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: 1b3f79f9896a4262a5ff57cf41214b1b; no voters: 
I20260812 06:19:54.589260 26600 leader_election.cc:290] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.589489 26604 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.589751 26604 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 1 LEADER]: Becoming Leader. State: Replica: 1b3f79f9896a4262a5ff57cf41214b1b, State: Running, Role: LEADER
I20260812 06:19:54.590212 26604 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [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: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER }
I20260812 06:19:54.590387 26600 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:54.592223 26605 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER } }
I20260812 06:19:54.592275 26607 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1b3f79f9896a4262a5ff57cf41214b1b. Latest consensus state: current_term: 1 leader_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3f79f9896a4262a5ff57cf41214b1b" member_type: VOTER } }
I20260812 06:19:54.592373 26605 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.592382 26607 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.592852 26522 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:54.592824 26622 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:54.595403 26622 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:54.600353 26622 catalog_manager.cc:1383] Generated new cluster ID: c2adf38d13c14b588a8f394bb22939e8
I20260812 06:19:54.600426 26622 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:54.619302 26622 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:54.620278 26622 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:54.625627 26622 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: Generated new TSK 0
I20260812 06:19:54.626426 26622 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:54.657832 26522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.661227 26628 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.661338 26631 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.661409 26522 server_base.cc:1061] running on GCE node
W20260812 06:19:54.661712 26633 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.661971 26522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.662041 26522 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.662078 26522 hybrid_clock.cc:648] HybridClock initialized: now 1786515594662077 us; error 0 us; skew 500 ppm
I20260812 06:19:54.663167 26522 webserver.cc:533] Webserver started at http://127.25.230.129:43485/ using document root <none> and password file <none>
I20260812 06:19:54.663355 26522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.663429 26522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.663515 26522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.663952 26522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/instance:
uuid: "eef42df5dd204e7f960a6e89e3851ed5"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-tm1g"
I20260812 06:19:54.665588 26522 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:54.666661 26638 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.666939 26522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:54.667022 26522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root
uuid: "eef42df5dd204e7f960a6e89e3851ed5"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-tm1g"
I20260812 06:19:54.667124 26522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:54.675420 26522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.675930 26522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.676468 26522 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:54.677333 26522 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:54.677385 26522 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.677459 26522 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:54.677500 26522 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.684379 26522 rpc_server.cc:307] RPC server started. Bound to: 127.25.230.129:35183
I20260812 06:19:54.684403 26704 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.230.129:35183 every 8 connection(s)
I20260812 06:19:54.695117 26705 heartbeater.cc:344] Connected to a master server at 127.25.230.190:44225
I20260812 06:19:54.695405 26705 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:54.695885 26705 heartbeater.cc:507] Master 127.25.230.190:44225 requested a full tablet report, sending...
I20260812 06:19:54.697449 26558 ts_manager.cc:194] Registered new tserver with Master: eef42df5dd204e7f960a6e89e3851ed5 (127.25.230.129:35183)
I20260812 06:19:54.697713 26522 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012632108s
I20260812 06:19:54.699059 26558 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57416
I20260812 06:19:54.708033 26558 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57424:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:54.722956 26666 tablet_service.cc:1511] Processing CreateTablet for tablet 76343f2e8cd54a71aa02adfe53bd25c8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fd5ba964aa0a42629415e0dfa75f4998]), partition=
I20260812 06:19:54.723487 26666 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 76343f2e8cd54a71aa02adfe53bd25c8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.726032 26722 tablet_bootstrap.cc:492] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Bootstrap starting.
I20260812 06:19:54.727326 26722 tablet_bootstrap.cc:654] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.729215 26722 tablet_bootstrap.cc:492] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: No bootstrap required, opened a new log
I20260812 06:19:54.729362 26722 ts_tablet_manager.cc:1403] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:54.729949 26722 raft_consensus.cc:359] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eef42df5dd204e7f960a6e89e3851ed5" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 35183 } }
I20260812 06:19:54.730090 26722 raft_consensus.cc:385] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.730132 26722 raft_consensus.cc:740] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: eef42df5dd204e7f960a6e89e3851ed5, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.730351 26722 consensus_queue.cc:260] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [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: "eef42df5dd204e7f960a6e89e3851ed5" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 35183 } }
I20260812 06:19:54.730458 26722 raft_consensus.cc:399] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.730495 26722 raft_consensus.cc:493] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.730548 26722 raft_consensus.cc:3060] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.731647 26722 raft_consensus.cc:515] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eef42df5dd204e7f960a6e89e3851ed5" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 35183 } }
I20260812 06:19:54.731806 26722 leader_election.cc:304] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [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: eef42df5dd204e7f960a6e89e3851ed5; no voters: 
I20260812 06:19:54.732048 26722 leader_election.cc:290] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.732272 26725 raft_consensus.cc:2804] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.732427 26722 ts_tablet_manager.cc:1434] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:54.732630 26725 raft_consensus.cc:697] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 1 LEADER]: Becoming Leader. State: Replica: eef42df5dd204e7f960a6e89e3851ed5, State: Running, Role: LEADER
I20260812 06:19:54.732726 26705 heartbeater.cc:499] Master 127.25.230.190:44225 was elected leader, sending a full tablet report...
I20260812 06:19:54.732856 26725 consensus_queue.cc:237] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [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: "eef42df5dd204e7f960a6e89e3851ed5" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 35183 } }
I20260812 06:19:54.736007 26558 catalog_manager.cc:5719] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 reported cstate change: term changed from 0 to 1, leader changed from <none> to eef42df5dd204e7f960a6e89e3851ed5 (127.25.230.129). New cstate: current_term: 1 leader_uuid: "eef42df5dd204e7f960a6e89e3851ed5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eef42df5dd204e7f960a6e89e3851ed5" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 35183 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:54.810527 26522 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.026s	sys 0.008s
I20260812 06:19:54.935578 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=15.086190
I20260812 06:19:55.097085 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.161s	user 0.119s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":291,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1100,"drs_written":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37620,"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:19:55.098407 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8): free 11976772 bytes of WAL
I20260812 06:19:55.098737 26643 log_reader.cc:385] T 76343f2e8cd54a71aa02adfe53bd25c8: removed 1 log segments from log reader
I20260812 06:19:55.098801 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000001 (ops 1-6)
I20260812 06:19:55.102145 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:55.102595 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8): 12308959 bytes on disk
I20260812 06:19:55.103274 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.103708 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:55.122479 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.123133 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:55.264441 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.141s	user 0.109s	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":442,"lbm_read_time_us":9781,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25897,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":300,"threads_started":5,"update_count":2000}
I20260812 06:19:55.265112 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:55.309659 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.044s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12471590,"delete_count":0,"lbm_write_time_us":19176,"lbm_writes_lt_1ms":307,"reinsert_count":0,"update_count":1520}
I20260812 06:19:55.310185 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:55.321691 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:55.322427 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:55.447806 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.125s	user 0.100s	sys 0.024s 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":1092,"lbm_read_time_us":9215,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23319,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:19:55.448485 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:55.496896 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22245,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.497484 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:55.509949 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.510516 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:55.633200 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.123s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":8770,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24466,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:19:55.633756 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:55.686582 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.053s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15578,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.687198 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:55.698485 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.699034 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:55.865710 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.166s	user 0.111s	sys 0.043s 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":842,"lbm_read_time_us":10953,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23382,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2000}
I20260812 06:19:55.866443 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:55.915005 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.048s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18238,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.915604 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:55.929812 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.930378 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:56.070991 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":581,"lbm_read_time_us":10855,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28311,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:19:56.071720 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:56.120170 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.048s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19430,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.120743 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:56.134249 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.134943 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:56.269703 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.135s	user 0.093s	sys 0.041s 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":558,"lbm_read_time_us":9670,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27771,"lbm_writes_lt_1ms":443,"mutex_wait_us":123,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:19:56.270476 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:56.318145 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.047s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16386,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.318717 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:56.334117 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.334852 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:56.375725 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1708,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1623,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:56.376535 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8): free 116849461 bytes of WAL
I20260812 06:19:56.376771 26643 log_reader.cc:385] T 76343f2e8cd54a71aa02adfe53bd25c8: removed 12 log segments from log reader
I20260812 06:19:56.376814 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000002 (ops 7-11)
I20260812 06:19:56.376845 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000003 (ops 12-16)
I20260812 06:19:56.376914 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000004 (ops 17-20)
I20260812 06:19:56.376946 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000005 (ops 21-25)
I20260812 06:19:56.376989 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000006 (ops 26-30)
I20260812 06:19:56.377039 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000007 (ops 31-34)
I20260812 06:19:56.377079 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000008 (ops 35-39)
I20260812 06:19:56.377117 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000009 (ops 40-44)
I20260812 06:19:56.377156 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000010 (ops 45-49)
I20260812 06:19:56.377194 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000011 (ops 50-54)
I20260812 06:19:56.377233 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000012 (ops 55-58)
I20260812 06:19:56.377271 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000013 (ops 59-63)
I20260812 06:19:56.402715 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:56.403179 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:56.420835 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.016s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.421398 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8): 448 bytes on disk
I20260812 06:19:56.422008 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.422595 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:56.433549 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.433980 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:56.656486 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.222s	user 0.144s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3157,"lbm_read_time_us":13956,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40238,"lbm_writes_lt_1ms":643,"mutex_wait_us":2166,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:19:56.657209 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:56.723765 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.066s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24474,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.724311 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:56.735635 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.736289 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:56.917029 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.181s	user 0.128s	sys 0.048s 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":1126,"lbm_read_time_us":11481,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31652,"lbm_writes_lt_1ms":543,"mutex_wait_us":404,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:56.917661 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:56.982769 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.065s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.983436 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.000823 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.001552 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:57.197960 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.196s	user 0.112s	sys 0.073s 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":224,"lbm_read_time_us":14320,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32506,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:19:57.198756 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:57.264447 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.065s	user 0.022s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26495,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.265033 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.276058 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.276610 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:57.454238 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.177s	user 0.109s	sys 0.068s 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":663,"lbm_read_time_us":13505,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29978,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:57.457127 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=10.126437
I20260812 06:19:57.504949 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.047s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":23058,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":299,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.505504 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.526122 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.020s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.526770 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.547163 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.020s	user 0.001s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.547710 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:57.747856 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.200s	user 0.130s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":177,"lbm_read_time_us":16173,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30906,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:57.748646 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=11.118625
I20260812 06:19:57.798929 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":23706,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.799535 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.823045 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.023s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.823681 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:57.835803 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.836792 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:58.030452 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.193s	user 0.144s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1193,"lbm_read_time_us":12302,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33721,"lbm_writes_lt_1ms":543,"mutex_wait_us":233,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.031260 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=11.118625
I20260812 06:19:58.076191 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.045s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18164,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.077133 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.105670 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.028s	user 0.014s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":8441,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.106235 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.121260 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.122083 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:58.210355 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.088s	user 0.068s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":3084,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:58.211737 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8): free 136728283 bytes of WAL
I20260812 06:19:58.212105 26643 log_reader.cc:385] T 76343f2e8cd54a71aa02adfe53bd25c8: removed 13 log segments from log reader
I20260812 06:19:58.212170 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000014 (ops 64-68)
I20260812 06:19:58.212209 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000015 (ops 69-73)
I20260812 06:19:58.212275 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000016 (ops 74-78)
I20260812 06:19:58.212314 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000017 (ops 79-83)
I20260812 06:19:58.212337 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000018 (ops 84-88)
I20260812 06:19:58.212395 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000019 (ops 89-93)
I20260812 06:19:58.212438 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000020 (ops 94-98)
I20260812 06:19:58.212463 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000021 (ops 99-103)
I20260812 06:19:58.212520 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000022 (ops 104-108)
I20260812 06:19:58.212554 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000023 (ops 109-113)
I20260812 06:19:58.212580 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000024 (ops 114-118)
I20260812 06:19:58.212641 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000025 (ops 119-123)
I20260812 06:19:58.212678 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000026 (ops 124-128)
I20260812 06:19:58.252537 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.041s	user 0.001s	sys 0.034s Metrics: {}
I20260812 06:19:58.253123 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8): 492 bytes on disk
I20260812 06:19:58.253654 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.254730 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=7.149875
I20260812 06:19:58.293833 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.039s	user 0.024s	sys 0.013s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":15820,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:58.294819 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.338200 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.043s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7351,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.339061 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.359995 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.021s	user 0.010s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.360633 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:58.648156 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.287s	user 0.197s	sys 0.088s Metrics: {"cfile_cache_miss":936,"cfile_cache_miss_bytes":41143831,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":6,"delta_iterators_relevant":6,"dirs.queue_time_us":542,"lbm_read_time_us":18152,"lbm_reads_lt_1ms":976,"lbm_write_time_us":51705,"lbm_writes_lt_1ms":943,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":455,"threads_started":6,"update_count":4500}
I20260812 06:19:58.649065 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:58.703890 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.055s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23989,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.704434 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.731593 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.027s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.732106 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:58.886397 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.154s	user 0.128s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1057,"lbm_read_time_us":9228,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29002,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:19:58.887202 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:58.945479 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.058s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25811,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.946074 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:58.961555 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.962076 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:59.139763 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.177s	user 0.130s	sys 0.043s 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":813,"lbm_read_time_us":12842,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34317,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:19:59.140439 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:59.204233 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.064s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23418,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.204790 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:59.215937 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.216885 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:59.390641 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.173s	user 0.103s	sys 0.066s 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":647,"lbm_read_time_us":12229,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28742,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:19:59.391378 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:19:59.458389 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.067s	user 0.033s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23856,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.458992 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:59.470762 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.471460 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:59.653291 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.182s	user 0.108s	sys 0.072s 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":233,"lbm_read_time_us":14200,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35098,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":96,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:59.653995 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=11.118625
I20260812 06:19:59.702600 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.048s	user 0.039s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19749,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:59.703243 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:19:59.718034 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4943,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.720033 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:19:59.763794 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushMRSOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.043s	user 0.025s	sys 0.008s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1711,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2006,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:59.764516 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8): free 112692608 bytes of WAL
I20260812 06:19:59.764767 26643 log_reader.cc:385] T 76343f2e8cd54a71aa02adfe53bd25c8: removed 11 log segments from log reader
I20260812 06:19:59.764832 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000027 (ops 129-133)
I20260812 06:19:59.764889 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000028 (ops 134-138)
I20260812 06:19:59.764948 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000029 (ops 139-143)
I20260812 06:19:59.764989 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000030 (ops 144-148)
I20260812 06:19:59.765025 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000031 (ops 149-153)
I20260812 06:19:59.765064 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000032 (ops 154-158)
I20260812 06:19:59.765100 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000033 (ops 159-163)
I20260812 06:19:59.765137 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000034 (ops 164-168)
I20260812 06:19:59.765173 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000035 (ops 169-173)
I20260812 06:19:59.765210 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000036 (ops 174-178)
I20260812 06:19:59.765246 26643 log.cc:1079] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/76343f2e8cd54a71aa02adfe53bd25c8/wal-000000037 (ops 179-183)
I20260812 06:19:59.793401 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: LogGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:59.793876 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8): 463 bytes on disk
I20260812 06:19:59.794471 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: UndoDeltaBlockGCOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.795135 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=6.157687
I20260812 06:19:59.824242 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.029s	user 0.014s	sys 0.011s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":11062,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:59.824935 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:20:00.036748 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.212s	user 0.168s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836248,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":960,"lbm_read_time_us":13270,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38455,"lbm_writes_lt_1ms":643,"mutex_wait_us":389,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":47360,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:20:00.037508 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=14.095187
I20260812 06:20:00.094916 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.057s	user 0.025s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25605,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.095453 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=3.181125
I20260812 06:20:00.113061 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5245,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:00.113580 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=2.188937
I20260812 06:20:00.124367 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: FlushDeltaMemStoresOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.124894 26707 maintenance_manager.cc:419] P eef42df5dd204e7f960a6e89e3851ed5: Scheduling MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8): perf score=1.000000
I20260812 06:20:00.164063 26522 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.353s	user 1.908s	sys 0.154s
I20260812 06:20:00.248600 26522 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.004s	sys 0.000s
I20260812 06:20:00.249450 26522 tablet_server.cc:179] TabletServer@127.25.230.129:0 shutting down...
I20260812 06:20:00.304630 26643 maintenance_manager.cc:643] P eef42df5dd204e7f960a6e89e3851ed5: MajorDeltaCompactionOp(76343f2e8cd54a71aa02adfe53bd25c8) complete. Timing: real 0.180s	user 0.120s	sys 0.058s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836244,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":385,"lbm_read_time_us":14255,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34215,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:20:00.305594 26522 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.306077 26522 tablet_replica.cc:333] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5: stopping tablet replica
I20260812 06:20:00.306641 26522 raft_consensus.cc:2243] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.306932 26522 raft_consensus.cc:2272] T 76343f2e8cd54a71aa02adfe53bd25c8 P eef42df5dd204e7f960a6e89e3851ed5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.337952 26522 tablet_server.cc:196] TabletServer@127.25.230.129:0 shutdown complete.
I20260812 06:20:00.360582 26522 master.cc:562] Master@127.25.230.190:44225 shutting down...
I20260812 06:20:00.365561 26522 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.365789 26522 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.365881 26522 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1b3f79f9896a4262a5ff57cf41214b1b: stopping tablet replica
I20260812 06:20:00.378851 26522 master.cc:584] Master@127.25.230.190:44225 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5974 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:00.476647 26522 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.230.190:44979
I20260812 06:20:00.477172 26522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.479707 26754 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.479755 26752 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.479840 26522 server_base.cc:1061] running on GCE node
W20260812 06:20:00.479707 26750 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.480192 26522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.480242 26522 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.480257 26522 hybrid_clock.cc:648] HybridClock initialized: now 1786515600480258 us; error 0 us; skew 500 ppm
I20260812 06:20:00.481308 26522 webserver.cc:533] Webserver started at http://127.25.230.190:39855/ using document root <none> and password file <none>
I20260812 06:20:00.481515 26522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.481583 26522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.481673 26522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.482112 26522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/master-0-root/instance:
uuid: "2fcbe9e1f518442da648ace520855fb0"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-tm1g"
I20260812 06:20:00.483716 26522 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.484809 26759 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.485121 26522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.485199 26522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/master-0-root
uuid: "2fcbe9e1f518442da648ace520855fb0"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-tm1g"
I20260812 06:20:00.485251 26522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.508345 26522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.508760 26522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.513032 26522 rpc_server.cc:307] RPC server started. Bound to: 127.25.230.190:44979
I20260812 06:20:00.515043 26817 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.230.190:44979 every 8 connection(s)
I20260812 06:20:00.515558 26818 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.521031 26818 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0: Bootstrap starting.
I20260812 06:20:00.521849 26818 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.522987 26818 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0: No bootstrap required, opened a new log
I20260812 06:20:00.523387 26818 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER }
I20260812 06:20:00.523474 26818 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.523500 26818 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2fcbe9e1f518442da648ace520855fb0, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.523674 26818 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [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: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER }
I20260812 06:20:00.523764 26818 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.523789 26818 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.523825 26818 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.524526 26818 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER }
I20260812 06:20:00.524641 26818 leader_election.cc:304] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [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: 2fcbe9e1f518442da648ace520855fb0; no voters: 
I20260812 06:20:00.524796 26818 leader_election.cc:290] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.524978 26821 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.525182 26821 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 1 LEADER]: Becoming Leader. State: Replica: 2fcbe9e1f518442da648ace520855fb0, State: Running, Role: LEADER
I20260812 06:20:00.525308 26818 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.525336 26821 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [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: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER }
I20260812 06:20:00.525822 26822 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2fcbe9e1f518442da648ace520855fb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER } }
I20260812 06:20:00.525840 26824 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2fcbe9e1f518442da648ace520855fb0. Latest consensus state: current_term: 1 leader_uuid: "2fcbe9e1f518442da648ace520855fb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fcbe9e1f518442da648ace520855fb0" member_type: VOTER } }
I20260812 06:20:00.525971 26822 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.525987 26824 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.526528 26828 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.527300 26828 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.527527 26522 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.529569 26828 catalog_manager.cc:1383] Generated new cluster ID: 5908e1339a634fb9b433fdc65ceed8c8
I20260812 06:20:00.529634 26828 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.543154 26828 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.543913 26828 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.557215 26828 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0: Generated new TSK 0
I20260812 06:20:00.557461 26828 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.559911 26522 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.562005 26842 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.562078 26843 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.562177 26522 server_base.cc:1061] running on GCE node
W20260812 06:20:00.562122 26845 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.562485 26522 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.562582 26522 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.562610 26522 hybrid_clock.cc:648] HybridClock initialized: now 1786515600562609 us; error 0 us; skew 500 ppm
I20260812 06:20:00.563488 26522 webserver.cc:533] Webserver started at http://127.25.230.129:45635/ using document root <none> and password file <none>
I20260812 06:20:00.563712 26522 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.563788 26522 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.563868 26522 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.564281 26522 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/instance:
uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-tm1g"
I20260812 06:20:00.565865 26522 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.567045 26851 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.567304 26522 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:00.567456 26522 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root
uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-tm1g"
I20260812 06:20:00.567543 26522 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.582017 26522 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.582558 26522 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.582916 26522 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.583401 26522 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.583462 26522 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.583525 26522 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.583580 26522 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.588220 26522 rpc_server.cc:307] RPC server started. Bound to: 127.25.230.129:45995
I20260812 06:20:00.590878 26924 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.230.129:45995 every 8 connection(s)
I20260812 06:20:00.601300 26925 heartbeater.cc:344] Connected to a master server at 127.25.230.190:44979
I20260812 06:20:00.601475 26925 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.601751 26925 heartbeater.cc:507] Master 127.25.230.190:44979 requested a full tablet report, sending...
I20260812 06:20:00.602602 26777 ts_manager.cc:194] Registered new tserver with Master: cf9e58cbb9ce43e5ba1e1bc710a8ec3b (127.25.230.129:45995)
I20260812 06:20:00.602715 26522 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013560831s
I20260812 06:20:00.603545 26777 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58124
I20260812 06:20:00.610934 26777 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58136:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:00.620795 26883 tablet_service.cc:1511] Processing CreateTablet for tablet 92deda1b6b5b4d68969ca7808822cb21 (DEFAULT_TABLE table=heavy-update-compaction-test [id=de5f7ccc9cfb4260aff3afa3f2ecb038]), partition=
I20260812 06:20:00.621153 26883 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 92deda1b6b5b4d68969ca7808822cb21. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.623970 26940 tablet_bootstrap.cc:492] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Bootstrap starting.
I20260812 06:20:00.624945 26940 tablet_bootstrap.cc:654] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.626621 26940 tablet_bootstrap.cc:492] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: No bootstrap required, opened a new log
I20260812 06:20:00.626765 26940 ts_tablet_manager.cc:1403] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:00.627419 26940 raft_consensus.cc:359] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 45995 } }
I20260812 06:20:00.627525 26940 raft_consensus.cc:385] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.627552 26940 raft_consensus.cc:740] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cf9e58cbb9ce43e5ba1e1bc710a8ec3b, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.627718 26940 consensus_queue.cc:260] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [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: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 45995 } }
I20260812 06:20:00.627820 26940 raft_consensus.cc:399] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.627849 26940 raft_consensus.cc:493] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.627893 26940 raft_consensus.cc:3060] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.628746 26940 raft_consensus.cc:515] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 45995 } }
I20260812 06:20:00.628890 26940 leader_election.cc:304] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [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: cf9e58cbb9ce43e5ba1e1bc710a8ec3b; no voters: 
I20260812 06:20:00.629084 26940 leader_election.cc:290] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.629314 26942 raft_consensus.cc:2804] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.629454 26940 ts_tablet_manager.cc:1434] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:00.629484 26925 heartbeater.cc:499] Master 127.25.230.190:44979 was elected leader, sending a full tablet report...
I20260812 06:20:00.629483 26942 raft_consensus.cc:697] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 1 LEADER]: Becoming Leader. State: Replica: cf9e58cbb9ce43e5ba1e1bc710a8ec3b, State: Running, Role: LEADER
I20260812 06:20:00.629730 26942 consensus_queue.cc:237] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [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: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 45995 } }
I20260812 06:20:00.631376 26777 catalog_manager.cc:5719] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b reported cstate change: term changed from 0 to 1, leader changed from <none> to cf9e58cbb9ce43e5ba1e1bc710a8ec3b (127.25.230.129). New cstate: current_term: 1 leader_uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf9e58cbb9ce43e5ba1e1bc710a8ec3b" member_type: VOTER last_known_addr { host: "127.25.230.129" port: 45995 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.692910 26522 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.015s	sys 0.009s
I20260812 06:20:00.841444 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21): perf score=19.054940
I20260812 06:20:01.006572 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.165s	user 0.124s	sys 0.040s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1365,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42183,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:01.007452 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling LogGCOp(92deda1b6b5b4d68969ca7808822cb21): free 20743880 bytes of WAL
I20260812 06:20:01.007696 26857 log_reader.cc:385] T 92deda1b6b5b4d68969ca7808822cb21: removed 2 log segments from log reader
I20260812 06:20:01.007742 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000001 (ops 1-6)
I20260812 06:20:01.007774 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000002 (ops 7-11)
I20260812 06:20:01.012223 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: LogGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:01.012586 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:01.029526 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.030009 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:01.191937 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.162s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":11477,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27297,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":309,"threads_started":5,"update_count":2000}
I20260812 06:20:01.192471 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:01.249328 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.057s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21501,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.249845 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:01.260411 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.260812 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:01.446435 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.185s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":775,"lbm_read_time_us":11953,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31797,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:20:01.447185 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21): 16411396 bytes on disk
I20260812 06:20:01.447629 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.448083 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:01.514110 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.066s	user 0.021s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26088,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.514694 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:01.532362 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.533048 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:01.751106 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.218s	user 0.131s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":15997,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34479,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:20:01.751919 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:01.811303 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.059s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22801,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.811965 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:01.829900 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.830410 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:02.018733 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.188s	user 0.128s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1031,"lbm_read_time_us":13107,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28575,"lbm_writes_lt_1ms":543,"mutex_wait_us":348,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:20:02.019213 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:02.073264 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.054s	user 0.037s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22576,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.073786 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:02.098748 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.025s	user 0.002s	sys 0.022s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.099339 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:02.293994 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.194s	user 0.121s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1427,"lbm_read_time_us":13691,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29726,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:20:02.294576 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:02.353004 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.058s	user 0.030s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29553,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":398,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.353574 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:02.368824 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.369386 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:02.409137 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.039s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1692,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2576,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:02.409795 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling LogGCOp(92deda1b6b5b4d68969ca7808822cb21): free 112692367 bytes of WAL
I20260812 06:20:02.410076 26857 log_reader.cc:385] T 92deda1b6b5b4d68969ca7808822cb21: removed 11 log segments from log reader
I20260812 06:20:02.410168 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000003 (ops 12-16)
I20260812 06:20:02.410246 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000004 (ops 17-21)
I20260812 06:20:02.410287 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000005 (ops 22-26)
I20260812 06:20:02.411250 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000006 (ops 27-31)
I20260812 06:20:02.411301 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000007 (ops 32-36)
I20260812 06:20:02.411339 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000008 (ops 37-41)
I20260812 06:20:02.411375 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000009 (ops 42-46)
I20260812 06:20:02.411417 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000010 (ops 47-51)
I20260812 06:20:02.411453 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000011 (ops 52-56)
I20260812 06:20:02.411490 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000012 (ops 57-61)
I20260812 06:20:02.411528 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000013 (ops 62-66)
I20260812 06:20:02.438699 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: LogGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:02.439311 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21): 462 bytes on disk
I20260812 06:20:02.439846 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.440357 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=3.181125
I20260812 06:20:02.458359 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.018s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:02.458819 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:02.469281 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.469775 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:02.727110 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.257s	user 0.171s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6332,"lbm_read_time_us":16860,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39916,"lbm_writes_lt_1ms":743,"mutex_wait_us":1471,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:20:02.727878 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=18.063937
I20260812 06:20:02.799203 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.071s	user 0.037s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26171,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.799738 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:02.812992 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.813619 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:03.031267 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.217s	user 0.125s	sys 0.087s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":14531,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35224,"lbm_writes_lt_1ms":643,"mutex_wait_us":17,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29056,"update_count":3000}
I20260812 06:20:03.032075 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=18.063937
I20260812 06:20:03.106369 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.074s	user 0.041s	sys 0.022s Metrics: {"bytes_written":20512407,"delete_count":0,"lbm_write_time_us":28396,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.107069 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:03.118705 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.119235 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:03.341027 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.222s	user 0.128s	sys 0.082s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877194,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":14710,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34885,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:20:03.341923 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=18.063937
I20260812 06:20:03.418447 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.076s	user 0.047s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30582,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.419036 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:03.432258 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4500,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.432772 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:03.646489 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.214s	user 0.131s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":609,"lbm_read_time_us":13533,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36606,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":3000}
I20260812 06:20:03.647357 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=15.087375
I20260812 06:20:03.688663 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.041s	user 0.018s	sys 0.021s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":18668,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:03.689285 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:03.704111 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5414,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.704659 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:03.885455 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.181s	user 0.125s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1161,"lbm_read_time_us":13243,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29925,"lbm_writes_lt_1ms":543,"mutex_wait_us":367,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2500}
I20260812 06:20:03.886238 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:03.948130 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.062s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27437,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.948894 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:03.964695 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.965178 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:03.994767 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1645,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1645,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:03.995425 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling LogGCOp(92deda1b6b5b4d68969ca7808822cb21): free 124257190 bytes of WAL
I20260812 06:20:03.995668 26857 log_reader.cc:385] T 92deda1b6b5b4d68969ca7808822cb21: removed 12 log segments from log reader
I20260812 06:20:03.995712 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000014 (ops 67-71)
I20260812 06:20:03.995743 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000015 (ops 72-76)
I20260812 06:20:03.995802 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000016 (ops 77-81)
I20260812 06:20:03.995860 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000017 (ops 82-86)
I20260812 06:20:03.995903 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000018 (ops 87-91)
I20260812 06:20:03.995939 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000019 (ops 92-96)
I20260812 06:20:03.995981 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000020 (ops 97-100)
I20260812 06:20:03.996019 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000021 (ops 101-105)
I20260812 06:20:03.996069 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000022 (ops 106-110)
I20260812 06:20:03.996115 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000023 (ops 111-115)
I20260812 06:20:03.996158 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000024 (ops 116-120)
I20260812 06:20:03.996196 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000025 (ops 121-125)
I20260812 06:20:04.025405 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: LogGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:04.025897 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=6.157687
I20260812 06:20:04.049265 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.023s	user 0.021s	sys 0.000s Metrics: {"bytes_written":7589714,"delete_count":0,"lbm_write_time_us":9853,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:20:04.050225 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling LogGCOp(92deda1b6b5b4d68969ca7808822cb21): free 8767182 bytes of WAL
I20260812 06:20:04.050577 26857 log_reader.cc:385] T 92deda1b6b5b4d68969ca7808822cb21: removed 1 log segments from log reader
I20260812 06:20:04.050647 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000026 (ops 126-130)
I20260812 06:20:04.053238 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: LogGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:04.053699 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:04.274551 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.221s	user 0.162s	sys 0.057s Metrics: {"cfile_cache_miss":718,"cfile_cache_miss_bytes":32364268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":989,"lbm_read_time_us":15211,"lbm_reads_lt_1ms":754,"lbm_write_time_us":40499,"lbm_writes_lt_1ms":728,"mutex_wait_us":58,"peak_mem_usage":85272751,"reinsert_count":0,"spinlock_wait_cycles":24960,"thread_start_us":76,"threads_started":1,"update_count":3425}
I20260812 06:20:04.275220 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=19.056125
I20260812 06:20:04.333701 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.058s	user 0.040s	sys 0.012s Metrics: {"bytes_written":21127681,"delete_count":0,"lbm_write_time_us":25577,"lbm_writes_lt_1ms":518,"reinsert_count":0,"update_count":2575}
I20260812 06:20:04.334354 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:04.347725 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.348184 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21): 482 bytes on disk
I20260812 06:20:04.348683 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.349344 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:04.523001 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.173s	user 0.138s	sys 0.035s Metrics: {"cfile_cache_miss":647,"cfile_cache_miss_bytes":29492468,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":12390,"lbm_reads_lt_1ms":687,"lbm_write_time_us":36727,"lbm_writes_lt_1ms":658,"mutex_wait_us":39,"peak_mem_usage":77198381,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3075}
I20260812 06:20:04.523818 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:04.573848 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.050s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22535,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.574596 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:04.587604 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.588106 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:04.750909 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.163s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":9751,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29887,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:20:04.751567 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=13.103000
I20260812 06:20:04.798875 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.047s	user 0.036s	sys 0.008s Metrics: {"bytes_written":15015080,"delete_count":0,"lbm_write_time_us":19483,"lbm_writes_lt_1ms":369,"reinsert_count":0,"update_count":1830}
I20260812 06:20:04.799414 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:04.809176 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.010s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2174487,"delete_count":0,"lbm_write_time_us":2391,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:20:04.809659 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:04.818843 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":3344,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:04.819296 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:05.003196 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.184s	user 0.121s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":182,"lbm_read_time_us":12548,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30645,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:20:05.004031 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:05.070604 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.066s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25135,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.071152 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:05.082296 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:20:05.083127 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:05.270797 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.187s	user 0.131s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":11594,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32747,"lbm_writes_lt_1ms":543,"mutex_wait_us":352,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:05.271648 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:05.335297 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.063s	user 0.038s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23521,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.336129 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:05.349855 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.350520 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:05.530879 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.180s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":11860,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30377,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:20:05.531735 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=14.095187
I20260812 06:20:05.595005 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.063s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23838,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.595660 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:05.608500 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.609089 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:05.655367 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushMRSOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.046s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1521,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2161,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:05.656160 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling LogGCOp(92deda1b6b5b4d68969ca7808822cb21): free 132118552 bytes of WAL
I20260812 06:20:05.656451 26857 log_reader.cc:385] T 92deda1b6b5b4d68969ca7808822cb21: removed 13 log segments from log reader
I20260812 06:20:05.656525 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000027 (ops 131-134)
I20260812 06:20:05.656594 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000028 (ops 135-139)
I20260812 06:20:05.656654 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000029 (ops 140-144)
I20260812 06:20:05.656702 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000030 (ops 145-149)
I20260812 06:20:05.656752 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000031 (ops 150-154)
I20260812 06:20:05.656796 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000032 (ops 155-159)
I20260812 06:20:05.656842 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000033 (ops 160-164)
I20260812 06:20:05.656888 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000034 (ops 165-168)
I20260812 06:20:05.656932 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000035 (ops 169-173)
I20260812 06:20:05.656976 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000036 (ops 174-178)
I20260812 06:20:05.657020 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000037 (ops 179-182)
I20260812 06:20:05.657064 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000038 (ops 183-187)
I20260812 06:20:05.657110 26857 log.cc:1079] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Deleting log segment in path: /tmp/dist-test-taskUvLEyx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594491297-26522-0/minicluster-data/ts-0-root/wals/92deda1b6b5b4d68969ca7808822cb21/wal-000000039 (ops 188-192)
I20260812 06:20:05.688882 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: LogGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:05.689323 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=3.181125
I20260812 06:20:05.703685 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.014s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5019,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:05.704205 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21): perf score=2.188937
I20260812 06:20:05.715494 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: FlushDeltaMemStoresOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.716012 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21): 492 bytes on disk
I20260812 06:20:05.716528 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: UndoDeltaBlockGCOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.717619 26926 maintenance_manager.cc:419] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: Scheduling MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21): perf score=1.000000
I20260812 06:20:05.807350 26522 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.114s	user 1.922s	sys 0.185s
I20260812 06:20:05.908625 26522 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.101s	user 0.001s	sys 0.000s
I20260812 06:20:05.909174 26522 tablet_server.cc:179] TabletServer@127.25.230.129:0 shutting down...
I20260812 06:20:05.957389 26857 maintenance_manager.cc:643] P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: MajorDeltaCompactionOp(92deda1b6b5b4d68969ca7808822cb21) complete. Timing: real 0.240s	user 0.147s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":529,"lbm_read_time_us":16864,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37723,"lbm_writes_lt_1ms":743,"mutex_wait_us":45,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:20:05.958581 26522 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.958889 26522 tablet_replica.cc:333] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b: stopping tablet replica
I20260812 06:20:05.959071 26522 raft_consensus.cc:2243] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.959263 26522 raft_consensus.cc:2272] T 92deda1b6b5b4d68969ca7808822cb21 P cf9e58cbb9ce43e5ba1e1bc710a8ec3b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.963899 26522 tablet_server.cc:196] TabletServer@127.25.230.129:0 shutdown complete.
I20260812 06:20:06.013684 26522 master.cc:562] Master@127.25.230.190:44979 shutting down...
I20260812 06:20:06.017489 26522 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.017678 26522 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.017733 26522 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2fcbe9e1f518442da648ace520855fb0: stopping tablet replica
I20260812 06:20:06.030418 26522 master.cc:584] Master@127.25.230.190:44979 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5652 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11628 ms total)

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