[==========] 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:05.850049 31572 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.213.62:38135
I20260812 06:19:05.851025 31572 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:05.851645 31572 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.857863 31586 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:05.857916 31572 server_base.cc:1061] running on GCE node
W20260812 06:19:05.857856 31584 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.858150 31581 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.858656 31572 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.858762 31572 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:05.858814 31572 hybrid_clock.cc:648] HybridClock initialized: now 1786515545858810 us; error 0 us; skew 500 ppm
I20260812 06:19:05.860602 31572 webserver.cc:533] Webserver started at http://127.30.213.62:35777/ using document root <none> and password file <none>
I20260812 06:19:05.861146 31572 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.861208 31572 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.861438 31572 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.863073 31572 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/master-0-root/instance:
uuid: "2d44b80bb4804a31abda974a05e06310"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-jpj1"
I20260812 06:19:05.866549 31572 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:05.868611 31596 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:05.869560 31572 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:05.869680 31572 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/master-0-root
uuid: "2d44b80bb4804a31abda974a05e06310"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-jpj1"
I20260812 06:19:05.869768 31572 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-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:05.887346 31572 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.888024 31572 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:05.888183 31572 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.895231 31572 rpc_server.cc:307] RPC server started. Bound to: 127.30.213.62:38135
I20260812 06:19:05.895279 31695 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.213.62:38135 every 8 connection(s)
I20260812 06:19:05.897424 31696 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:05.902927 31696 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: Bootstrap starting.
I20260812 06:19:05.905323 31696 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.906169 31696 log.cc:826] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:05.907893 31696 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: No bootstrap required, opened a new log
I20260812 06:19:05.910560 31696 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER }
I20260812 06:19:05.910718 31696 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.910772 31696 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d44b80bb4804a31abda974a05e06310, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.911348 31696 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [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: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER }
I20260812 06:19:05.911500 31696 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.911573 31696 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.911671 31696 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.912396 31696 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER }
I20260812 06:19:05.912791 31696 leader_election.cc:304] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [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: 2d44b80bb4804a31abda974a05e06310; no voters: 
I20260812 06:19:05.913050 31696 leader_election.cc:290] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.913215 31701 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.913442 31701 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 1 LEADER]: Becoming Leader. State: Replica: 2d44b80bb4804a31abda974a05e06310, State: Running, Role: LEADER
I20260812 06:19:05.913825 31701 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [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: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER }
I20260812 06:19:05.913992 31696 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:05.915737 31703 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2d44b80bb4804a31abda974a05e06310. Latest consensus state: current_term: 1 leader_uuid: "2d44b80bb4804a31abda974a05e06310" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER } }
I20260812 06:19:05.915861 31703 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.916101 31702 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2d44b80bb4804a31abda974a05e06310" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d44b80bb4804a31abda974a05e06310" member_type: VOTER } }
I20260812 06:19:05.916174 31722 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:05.916179 31702 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.916185 31572 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:05.918416 31722 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:05.922708 31722 catalog_manager.cc:1383] Generated new cluster ID: c5c0f6c210534a6ca82b102e66dd4681
I20260812 06:19:05.922778 31722 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.936993 31722 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.938189 31722 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.951560 31722 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: Generated new TSK 0
I20260812 06:19:05.952304 31722 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.981016 31572 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.983678 31735 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:05.983712 31738 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:05.983965 31736 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:05.984212 31572 server_base.cc:1061] running on GCE node
I20260812 06:19:05.984400 31572 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.984441 31572 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:05.984455 31572 hybrid_clock.cc:648] HybridClock initialized: now 1786515545984456 us; error 0 us; skew 500 ppm
I20260812 06:19:05.985430 31572 webserver.cc:533] Webserver started at http://127.30.213.1:41345/ using document root <none> and password file <none>
I20260812 06:19:05.985594 31572 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.985646 31572 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.985733 31572 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.986128 31572 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/instance:
uuid: "b22a4ffd4049434697e1c2915d9e617a"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-jpj1"
I20260812 06:19:05.987630 31572 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:05.988554 31745 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:05.988772 31572 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:05.988842 31572 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root
uuid: "b22a4ffd4049434697e1c2915d9e617a"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-jpj1"
I20260812 06:19:05.988910 31572 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-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:06.007568 31572 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:06.008257 31572 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:06.008741 31572 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:06.009626 31572 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:06.009683 31572 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:06.009733 31572 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:06.009763 31572 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:06.015925 31572 rpc_server.cc:307] RPC server started. Bound to: 127.30.213.1:37135
I20260812 06:19:06.016103 31869 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.213.1:37135 every 8 connection(s)
I20260812 06:19:06.028467 31870 heartbeater.cc:344] Connected to a master server at 127.30.213.62:38135
I20260812 06:19:06.028761 31870 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:06.029233 31870 heartbeater.cc:507] Master 127.30.213.62:38135 requested a full tablet report, sending...
I20260812 06:19:06.030658 31630 ts_manager.cc:194] Registered new tserver with Master: b22a4ffd4049434697e1c2915d9e617a (127.30.213.1:37135)
I20260812 06:19:06.031030 31572 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014449074s
I20260812 06:19:06.032184 31630 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49576
I20260812 06:19:06.040292 31630 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49592:
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:06.054548 31804 tablet_service.cc:1511] Processing CreateTablet for tablet d8db0292995641799e26256f071210e1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5c2c0c90c2be45309fd00712b01ee780]), partition=
I20260812 06:19:06.055009 31804 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d8db0292995641799e26256f071210e1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:06.057621 31894 tablet_bootstrap.cc:492] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Bootstrap starting.
I20260812 06:19:06.058727 31894 tablet_bootstrap.cc:654] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:06.060182 31894 tablet_bootstrap.cc:492] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: No bootstrap required, opened a new log
I20260812 06:19:06.060299 31894 ts_tablet_manager.cc:1403] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:06.060834 31894 raft_consensus.cc:359] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b22a4ffd4049434697e1c2915d9e617a" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 37135 } }
I20260812 06:19:06.060971 31894 raft_consensus.cc:385] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:06.061010 31894 raft_consensus.cc:740] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b22a4ffd4049434697e1c2915d9e617a, State: Initialized, Role: FOLLOWER
I20260812 06:19:06.061189 31894 consensus_queue.cc:260] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [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: "b22a4ffd4049434697e1c2915d9e617a" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 37135 } }
I20260812 06:19:06.061309 31894 raft_consensus.cc:399] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:06.061403 31894 raft_consensus.cc:493] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:06.061465 31894 raft_consensus.cc:3060] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:06.062444 31894 raft_consensus.cc:515] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b22a4ffd4049434697e1c2915d9e617a" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 37135 } }
I20260812 06:19:06.062597 31894 leader_election.cc:304] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [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: b22a4ffd4049434697e1c2915d9e617a; no voters: 
I20260812 06:19:06.062816 31894 leader_election.cc:290] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:06.062917 31897 raft_consensus.cc:2804] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:06.063127 31897 raft_consensus.cc:697] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 1 LEADER]: Becoming Leader. State: Replica: b22a4ffd4049434697e1c2915d9e617a, State: Running, Role: LEADER
I20260812 06:19:06.063184 31894 ts_tablet_manager.cc:1434] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:06.063408 31870 heartbeater.cc:499] Master 127.30.213.62:38135 was elected leader, sending a full tablet report...
I20260812 06:19:06.063488 31897 consensus_queue.cc:237] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [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: "b22a4ffd4049434697e1c2915d9e617a" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 37135 } }
I20260812 06:19:06.066129 31630 catalog_manager.cc:5719] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a reported cstate change: term changed from 0 to 1, leader changed from <none> to b22a4ffd4049434697e1c2915d9e617a (127.30.213.1). New cstate: current_term: 1 leader_uuid: "b22a4ffd4049434697e1c2915d9e617a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b22a4ffd4049434697e1c2915d9e617a" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 37135 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:06.126578 31572 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.016s	sys 0.007s
I20260812 06:19:06.267102 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushMRSOp(d8db0292995641799e26256f071210e1): perf score=19.054940
I20260812 06:19:06.444774 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushMRSOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.177s	user 0.129s	sys 0.028s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":1074,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":739,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40168,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":108,"threads_started":1,"update_count":1500}
I20260812 06:19:06.446036 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling LogGCOp(d8db0292995641799e26256f071210e1): free 20743880 bytes of WAL
I20260812 06:19:06.446339 31761 log_reader.cc:385] T d8db0292995641799e26256f071210e1: removed 2 log segments from log reader
I20260812 06:19:06.446398 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000001 (ops 1-6)
I20260812 06:19:06.446497 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000002 (ops 7-11)
I20260812 06:19:06.451885 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: LogGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:06.452291 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1): 16411394 bytes on disk
I20260812 06:19:06.452939 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.453462 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:06.467133 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.013s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.467737 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:06.605644 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.138s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":804,"lbm_read_time_us":7778,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24903,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":279,"threads_started":5,"update_count":2000}
I20260812 06:19:06.606238 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:06.650166 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.044s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17919,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.650686 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:06.666435 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.667024 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:06.787421 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.120s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":8963,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24092,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27520,"update_count":2000}
I20260812 06:19:06.787999 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:06.824184 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.036s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307502,"delete_count":0,"lbm_write_time_us":14105,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.824776 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:06.835407 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.835970 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:06.970884 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.135s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672289,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":712,"lbm_read_time_us":8914,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26650,"lbm_writes_lt_1ms":443,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:06.971398 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:07.020190 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.049s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15724,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.020802 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.031411 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.031886 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:07.172686 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.141s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":11073,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22168,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.173215 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:07.214447 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.041s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13241,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.214970 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.225558 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.226233 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:07.349793 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.123s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":644,"lbm_read_time_us":8524,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23871,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2000}
I20260812 06:19:07.350294 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:07.391985 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.042s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15489,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.392426 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.403329 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.403939 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:07.531148 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.126s	user 0.101s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":9999,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22603,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:07.531720 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:07.581559 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.050s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.582211 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.597870 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.598431 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushMRSOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:07.638140 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushMRSOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.040s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1116,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1385,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:07.638998 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling LogGCOp(d8db0292995641799e26256f071210e1): free 112239310 bytes of WAL
I20260812 06:19:07.639227 31761 log_reader.cc:385] T d8db0292995641799e26256f071210e1: removed 11 log segments from log reader
I20260812 06:19:07.639274 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000003 (ops 12-16)
I20260812 06:19:07.639302 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000004 (ops 17-21)
I20260812 06:19:07.639333 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000005 (ops 22-26)
I20260812 06:19:07.639364 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000006 (ops 27-31)
I20260812 06:19:07.639396 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000007 (ops 32-36)
I20260812 06:19:07.639424 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000008 (ops 37-41)
I20260812 06:19:07.639456 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000009 (ops 42-46)
I20260812 06:19:07.639482 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000010 (ops 47-50)
I20260812 06:19:07.639513 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000011 (ops 51-55)
I20260812 06:19:07.639569 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000012 (ops 56-60)
I20260812 06:19:07.639612 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000013 (ops 61-65)
I20260812 06:19:07.660526 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: LogGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:07.660951 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.683145 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.022s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.683696 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1): 447 bytes on disk
I20260812 06:19:07.684141 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1) 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:19:07.684644 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:07.694664 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.695264 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:07.892859 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.197s	user 0.126s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877342,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":512,"lbm_read_time_us":12617,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34869,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:07.893319 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=14.095187
I20260812 06:19:07.944617 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.051s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20992,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.945071 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:08.080853 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.136s	user 0.092s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":752,"lbm_read_time_us":9350,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20897,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:08.081393 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=11.118625
I20260812 06:19:08.128683 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":20590,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:08.129282 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.140930 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.141434 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.150758 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3371,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.151228 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:08.329396 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.178s	user 0.125s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1134,"lbm_read_time_us":9697,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30770,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:08.329910 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=11.118625
I20260812 06:19:08.367785 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.038s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12758763,"delete_count":0,"lbm_write_time_us":15830,"lbm_writes_lt_1ms":314,"reinsert_count":0,"update_count":1555}
I20260812 06:19:08.368462 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.381525 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":4813,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:08.382035 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:08.510478 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.128s	user 0.101s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":9107,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24982,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.511057 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=11.118625
I20260812 06:19:08.544255 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.033s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13942,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:08.544826 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.559679 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5325,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.560238 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:08.688472 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.128s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":9728,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22969,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:08.689102 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:08.730449 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.041s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15634,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.731024 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.741603 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.742267 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:08.862265 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.120s	user 0.107s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":9406,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21082,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":699648,"update_count":2000}
I20260812 06:19:08.862838 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:08.918534 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.056s	user 0.025s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":24191,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.919215 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:08.929697 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.930228 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.061542 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.131s	user 0.091s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":10601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20215,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.062076 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:09.103508 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.041s	user 0.012s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.104152 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:09.115087 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.115895 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushMRSOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.144867 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushMRSOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.029s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1182,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1866,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:09.145649 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling LogGCOp(d8db0292995641799e26256f071210e1): free 124710302 bytes of WAL
I20260812 06:19:09.145897 31761 log_reader.cc:385] T d8db0292995641799e26256f071210e1: removed 12 log segments from log reader
I20260812 06:19:09.145957 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000014 (ops 66-70)
I20260812 06:19:09.146001 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000015 (ops 71-75)
I20260812 06:19:09.146034 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000016 (ops 76-80)
I20260812 06:19:09.146067 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000017 (ops 81-85)
I20260812 06:19:09.146104 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000018 (ops 86-90)
I20260812 06:19:09.146133 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000019 (ops 91-95)
I20260812 06:19:09.146163 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000020 (ops 96-100)
I20260812 06:19:09.146194 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000021 (ops 101-105)
I20260812 06:19:09.146225 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000022 (ops 106-110)
I20260812 06:19:09.146252 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000023 (ops 111-115)
I20260812 06:19:09.146281 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000024 (ops 116-120)
I20260812 06:19:09.146311 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000025 (ops 121-125)
I20260812 06:19:09.173938 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: LogGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:09.174437 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1): 483 bytes on disk
I20260812 06:19:09.175176 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: UndoDeltaBlockGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.175850 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=4.173312
I20260812 06:19:09.201154 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.025s	user 0.008s	sys 0.016s Metrics: {"bytes_written":5661585,"delete_count":0,"lbm_write_time_us":6458,"lbm_writes_lt_1ms":141,"reinsert_count":0,"update_count":690}
I20260812 06:19:09.201689 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=1.196750
I20260812 06:19:09.212563 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3716,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:09.213126 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.416536 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.203s	user 0.147s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":121,"lbm_read_time_us":14809,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32093,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:09.417702 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=14.095187
I20260812 06:19:09.469550 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.051s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17180,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.470230 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:09.480710 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.481160 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.645376 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.164s	user 0.139s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":503,"lbm_read_time_us":12890,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25150,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:09.645893 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=11.118625
I20260812 06:19:09.680785 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.035s	user 0.011s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15919,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:09.681391 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:09.696462 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.696983 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.819901 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.123s	user 0.088s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":7828,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23698,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:19:09.820483 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:09.857599 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.037s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13911,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.858211 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:09.873745 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.015s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.874441 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:09.990814 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.116s	user 0.092s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":8261,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21493,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:19:09.991382 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:10.025210 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.034s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.025868 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:10.037168 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.037673 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:10.160254 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.122s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":8689,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23372,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.161012 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:10.212350 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.051s	user 0.039s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20137,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.213114 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:10.227885 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.228451 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:10.376652 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.148s	user 0.120s	sys 0.028s 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":575,"lbm_read_time_us":11415,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24234,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:10.377264 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:10.409188 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13374,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.409806 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:10.426578 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.427078 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:10.539099 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.112s	user 0.098s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":7413,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21190,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.539778 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=10.126437
I20260812 06:19:10.577999 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.038s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15585,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.578495 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:10.588629 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.589389 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushMRSOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:10.616146 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushMRSOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.026s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1128,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1345,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:10.616874 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling LogGCOp(d8db0292995641799e26256f071210e1): free 133477700 bytes of WAL
I20260812 06:19:10.617120 31761 log_reader.cc:385] T d8db0292995641799e26256f071210e1: removed 13 log segments from log reader
I20260812 06:19:10.617177 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000026 (ops 126-130)
I20260812 06:19:10.617224 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000027 (ops 131-135)
I20260812 06:19:10.617259 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000028 (ops 136-140)
I20260812 06:19:10.617280 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000029 (ops 141-145)
I20260812 06:19:10.617308 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000030 (ops 146-150)
I20260812 06:19:10.617336 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000031 (ops 151-155)
I20260812 06:19:10.617367 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000032 (ops 156-160)
I20260812 06:19:10.617398 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000033 (ops 161-165)
I20260812 06:19:10.617426 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000034 (ops 166-170)
I20260812 06:19:10.617455 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000035 (ops 171-175)
I20260812 06:19:10.617480 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000036 (ops 176-180)
I20260812 06:19:10.617509 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000037 (ops 181-185)
I20260812 06:19:10.617540 31761 log.cc:1079] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/d8db0292995641799e26256f071210e1/wal-000000038 (ops 186-190)
I20260812 06:19:10.647732 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: LogGCOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:10.648164 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=3.181125
I20260812 06:19:10.659583 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.011s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:10.660063 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=2.188937
I20260812 06:19:10.673842 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4949,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.674404 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1): perf score=1.000000
I20260812 06:19:10.845939 31572 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.719s	user 1.734s	sys 0.136s
I20260812 06:19:10.848315 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: MajorDeltaCompactionOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.174s	user 0.113s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":428,"lbm_read_time_us":13419,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32110,"lbm_writes_lt_1ms":643,"mutex_wait_us":190,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:10.849989 31872 maintenance_manager.cc:419] P b22a4ffd4049434697e1c2915d9e617a: Scheduling FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1): perf score=14.095187
I20260812 06:19:10.874591 31572 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.028s	user 0.002s	sys 0.000s
I20260812 06:19:10.875422 31572 tablet_server.cc:179] TabletServer@127.30.213.1:0 shutting down...
I20260812 06:19:10.888561 31761 maintenance_manager.cc:643] P b22a4ffd4049434697e1c2915d9e617a: FlushDeltaMemStoresOp(d8db0292995641799e26256f071210e1) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16764,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.889160 31572 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:10.889544 31572 tablet_replica.cc:333] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a: stopping tablet replica
I20260812 06:19:10.889799 31572 raft_consensus.cc:2243] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.890029 31572 raft_consensus.cc:2272] T d8db0292995641799e26256f071210e1 P b22a4ffd4049434697e1c2915d9e617a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.904747 31572 tablet_server.cc:196] TabletServer@127.30.213.1:0 shutdown complete.
I20260812 06:19:10.909358 31572 master.cc:562] Master@127.30.213.62:38135 shutting down...
I20260812 06:19:10.912317 31572 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.912467 31572 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.912519 31572 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2d44b80bb4804a31abda974a05e06310: stopping tablet replica
I20260812 06:19:10.924657 31572 master.cc:584] Master@127.30.213.62:38135 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5153 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:11.003019 31572 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.213.62:37147
I20260812 06:19:11.003422 31572 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.005295 31926 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:11.005504 31927 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.005477 31930 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:11.005493 31572 server_base.cc:1061] running on GCE node
I20260812 06:19:11.005764 31572 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.005807 31572 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:11.005827 31572 hybrid_clock.cc:648] HybridClock initialized: now 1786515551005827 us; error 0 us; skew 500 ppm
I20260812 06:19:11.006623 31572 webserver.cc:533] Webserver started at http://127.30.213.62:46823/ using document root <none> and password file <none>
I20260812 06:19:11.006769 31572 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.006821 31572 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.006894 31572 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.007247 31572 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/master-0-root/instance:
uuid: "006c800eb0e64de1853ab0c209949917"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-jpj1"
I20260812 06:19:11.008863 31572 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:11.009821 31939 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:11.010033 31572 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.010106 31572 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/master-0-root
uuid: "006c800eb0e64de1853ab0c209949917"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-jpj1"
I20260812 06:19:11.010185 31572 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-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:11.020404 31572 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.020805 31572 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.024950 31572 rpc_server.cc:307] RPC server started. Bound to: 127.30.213.62:37147
I20260812 06:19:11.039450 32024 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.213.62:37147 every 8 connection(s)
I20260812 06:19:11.039466 32027 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:11.041484 32027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917: Bootstrap starting.
I20260812 06:19:11.042281 32027 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.043339 32027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917: No bootstrap required, opened a new log
I20260812 06:19:11.043779 32027 raft_consensus.cc:359] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "006c800eb0e64de1853ab0c209949917" member_type: VOTER }
I20260812 06:19:11.043879 32027 raft_consensus.cc:385] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.043900 32027 raft_consensus.cc:740] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 006c800eb0e64de1853ab0c209949917, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.044050 32027 consensus_queue.cc:260] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [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: "006c800eb0e64de1853ab0c209949917" member_type: VOTER }
I20260812 06:19:11.044127 32027 raft_consensus.cc:399] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.044150 32027 raft_consensus.cc:493] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.044179 32027 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.044857 32027 raft_consensus.cc:515] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "006c800eb0e64de1853ab0c209949917" member_type: VOTER }
I20260812 06:19:11.044981 32027 leader_election.cc:304] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [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: 006c800eb0e64de1853ab0c209949917; no voters: 
I20260812 06:19:11.045173 32027 leader_election.cc:290] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.045306 32030 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.045493 32030 raft_consensus.cc:697] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 1 LEADER]: Becoming Leader. State: Replica: 006c800eb0e64de1853ab0c209949917, State: Running, Role: LEADER
I20260812 06:19:11.045653 32027 sys_catalog.cc:565] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:11.045631 32030 consensus_queue.cc:237] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [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: "006c800eb0e64de1853ab0c209949917" member_type: VOTER }
I20260812 06:19:11.046062 32031 sys_catalog.cc:455] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "006c800eb0e64de1853ab0c209949917" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "006c800eb0e64de1853ab0c209949917" member_type: VOTER } }
I20260812 06:19:11.046092 32032 sys_catalog.cc:455] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 006c800eb0e64de1853ab0c209949917. Latest consensus state: current_term: 1 leader_uuid: "006c800eb0e64de1853ab0c209949917" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "006c800eb0e64de1853ab0c209949917" member_type: VOTER } }
I20260812 06:19:11.046159 32031 sys_catalog.cc:458] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.046202 32032 sys_catalog.cc:458] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.046867 32035 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:11.047678 32035 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:11.047884 31572 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:11.049470 32035 catalog_manager.cc:1383] Generated new cluster ID: 35e76551d893426ba5710daaacab6a0c
I20260812 06:19:11.049523 32035 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:11.060716 32035 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:11.061267 32035 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:11.068203 32035 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917: Generated new TSK 0
I20260812 06:19:11.068380 32035 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:11.080369 31572 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.082268 32065 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:11.082391 31572 server_base.cc:1061] running on GCE node
W20260812 06:19:11.082409 32058 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:11.082568 32062 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:11.082778 31572 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.082830 31572 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:11.082844 31572 hybrid_clock.cc:648] HybridClock initialized: now 1786515551082844 us; error 0 us; skew 500 ppm
I20260812 06:19:11.083653 31572 webserver.cc:533] Webserver started at http://127.30.213.1:42931/ using document root <none> and password file <none>
I20260812 06:19:11.083817 31572 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.083861 31572 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.083994 31572 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.084365 31572 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/instance:
uuid: "5ee8ba0bb647425fab78151685476dd0"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-jpj1"
I20260812 06:19:11.085774 31572 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:11.086648 32076 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:11.086863 31572 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:11.086934 31572 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root
uuid: "5ee8ba0bb647425fab78151685476dd0"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-jpj1"
I20260812 06:19:11.087002 31572 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-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:11.092613 31572 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.092934 31572 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.093199 31572 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:11.093636 31572 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:11.093673 31572 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.093714 31572 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:11.093742 31572 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.097688 31572 rpc_server.cc:307] RPC server started. Bound to: 127.30.213.1:45393
I20260812 06:19:11.097750 32188 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.213.1:45393 every 8 connection(s)
I20260812 06:19:11.105535 32191 heartbeater.cc:344] Connected to a master server at 127.30.213.62:37147
I20260812 06:19:11.105645 32191 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:11.105901 32191 heartbeater.cc:507] Master 127.30.213.62:37147 requested a full tablet report, sending...
I20260812 06:19:11.106571 31973 ts_manager.cc:194] Registered new tserver with Master: 5ee8ba0bb647425fab78151685476dd0 (127.30.213.1:45393)
I20260812 06:19:11.106886 31572 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008782213s
I20260812 06:19:11.107564 31973 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54852
I20260812 06:19:11.113606 31973 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54866:
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:11.121822 32123 tablet_service.cc:1511] Processing CreateTablet for tablet f5b95731e2a144c6a0243de6ae3ec6d5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3e906eaec0a44bf495205dc81e1cad4a]), partition=
I20260812 06:19:11.122125 32123 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f5b95731e2a144c6a0243de6ae3ec6d5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.124146 32206 tablet_bootstrap.cc:492] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Bootstrap starting.
I20260812 06:19:11.125013 32206 tablet_bootstrap.cc:654] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.126027 32206 tablet_bootstrap.cc:492] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: No bootstrap required, opened a new log
I20260812 06:19:11.126102 32206 ts_tablet_manager.cc:1403] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:11.126495 32206 raft_consensus.cc:359] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5ee8ba0bb647425fab78151685476dd0" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 45393 } }
I20260812 06:19:11.126580 32206 raft_consensus.cc:385] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.126613 32206 raft_consensus.cc:740] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5ee8ba0bb647425fab78151685476dd0, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.126749 32206 consensus_queue.cc:260] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [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: "5ee8ba0bb647425fab78151685476dd0" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 45393 } }
I20260812 06:19:11.126823 32206 raft_consensus.cc:399] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.126863 32206 raft_consensus.cc:493] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.126915 32206 raft_consensus.cc:3060] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.127696 32206 raft_consensus.cc:515] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5ee8ba0bb647425fab78151685476dd0" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 45393 } }
I20260812 06:19:11.127826 32206 leader_election.cc:304] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [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: 5ee8ba0bb647425fab78151685476dd0; no voters: 
I20260812 06:19:11.127979 32206 leader_election.cc:290] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.128087 32209 raft_consensus.cc:2804] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.128273 32206 ts_tablet_manager.cc:1434] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:11.128330 32209 raft_consensus.cc:697] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 1 LEADER]: Becoming Leader. State: Replica: 5ee8ba0bb647425fab78151685476dd0, State: Running, Role: LEADER
I20260812 06:19:11.128372 32191 heartbeater.cc:499] Master 127.30.213.62:37147 was elected leader, sending a full tablet report...
I20260812 06:19:11.128472 32209 consensus_queue.cc:237] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [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: "5ee8ba0bb647425fab78151685476dd0" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 45393 } }
I20260812 06:19:11.129769 31973 catalog_manager.cc:5719] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5ee8ba0bb647425fab78151685476dd0 (127.30.213.1). New cstate: current_term: 1 leader_uuid: "5ee8ba0bb647425fab78151685476dd0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5ee8ba0bb647425fab78151685476dd0" member_type: VOTER last_known_addr { host: "127.30.213.1" port: 45393 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:11.187518 31572 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.003s
I20260812 06:19:11.348613 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=19.054940
I20260812 06:19:11.497020 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.148s	user 0.097s	sys 0.046s Metrics: {"bytes_written":9722972,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":171,"dirs.run_wall_time_us":708,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37817,"lbm_writes_lt_1ms":794,"mutex_wait_us":839,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1185}
I20260812 06:19:11.497917 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): free 20743880 bytes of WAL
I20260812 06:19:11.498253 32082 log_reader.cc:385] T f5b95731e2a144c6a0243de6ae3ec6d5: removed 2 log segments from log reader
I20260812 06:19:11.498346 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000001 (ops 1-6)
I20260812 06:19:11.498400 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000002 (ops 7-11)
I20260812 06:19:11.502775 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:11.503326 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.196750
I20260812 06:19:11.512950 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":3255,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:19:11.513439 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:11.626716 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.113s	user 0.079s	sys 0.034s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569829,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":588,"lbm_read_time_us":7441,"lbm_reads_lt_1ms":364,"lbm_write_time_us":17316,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":304,"threads_started":5,"update_count":1500}
I20260812 06:19:11.627317 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:11.667061 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.040s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14504,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.667729 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): 20513802 bytes on disk
I20260812 06:19:11.668190 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.668680 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:11.787410 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.119s	user 0.090s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1337,"lbm_read_time_us":9234,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17576,"lbm_writes_lt_1ms":343,"mutex_wait_us":424,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.787976 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:11.822233 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.034s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14548,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.822813 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:11.837828 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.838399 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:11.960680 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.122s	user 0.082s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":776,"lbm_read_time_us":9591,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22111,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:11.961227 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:12.007925 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.046s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20321,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.008558 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.021266 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.021713 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:12.141501 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.120s	user 0.087s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":138,"lbm_read_time_us":8581,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23888,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29824,"update_count":2000}
I20260812 06:19:12.142021 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:12.192615 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.050s	user 0.037s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.193329 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.203960 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.204428 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:12.354521 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.150s	user 0.110s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":982,"lbm_read_time_us":10929,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24948,"lbm_writes_lt_1ms":443,"mutex_wait_us":315,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:12.355068 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:12.397330 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.042s	user 0.004s	sys 0.028s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14243,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.397816 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.408481 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.409138 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:12.534286 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.125s	user 0.101s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":8336,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23989,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2000}
I20260812 06:19:12.534941 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:12.582558 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.047s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16293,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.583146 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.593629 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.594390 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:12.713133 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.118s	user 0.093s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":9974,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20157,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":42880,"update_count":2000}
I20260812 06:19:12.713677 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:12.759809 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.046s	user 0.013s	sys 0.029s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16632,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:19:12.760385 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.770828 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.771620 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:12.797582 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.026s	user 0.018s	sys 0.005s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1283,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1383,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:12.798213 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): free 124710291 bytes of WAL
I20260812 06:19:12.798460 32082 log_reader.cc:385] T f5b95731e2a144c6a0243de6ae3ec6d5: removed 12 log segments from log reader
I20260812 06:19:12.798521 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000003 (ops 12-16)
I20260812 06:19:12.798568 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000004 (ops 17-21)
I20260812 06:19:12.798605 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000005 (ops 22-26)
I20260812 06:19:12.798626 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000006 (ops 27-31)
I20260812 06:19:12.798646 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000007 (ops 32-36)
I20260812 06:19:12.798668 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000008 (ops 37-41)
I20260812 06:19:12.798689 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000009 (ops 42-46)
I20260812 06:19:12.798722 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000010 (ops 47-51)
I20260812 06:19:12.798753 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000011 (ops 52-56)
I20260812 06:19:12.798780 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000012 (ops 57-61)
I20260812 06:19:12.798807 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000013 (ops 62-66)
I20260812 06:19:12.798838 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000014 (ops 67-71)
I20260812 06:19:12.825819 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:12.826269 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=3.181125
I20260812 06:19:12.840318 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4008,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:12.840762 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:12.854347 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.854868 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:13.028357 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.173s	user 0.129s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":733,"lbm_read_time_us":11927,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33767,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:13.028903 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): 482 bytes on disk
I20260812 06:19:13.029351 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) 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:19:13.029917 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:13.084502 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.054s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24017,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.084972 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.095867 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.096378 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:13.264278 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.168s	user 0.130s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1252,"lbm_read_time_us":11267,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29190,"lbm_writes_lt_1ms":543,"mutex_wait_us":396,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:19:13.264897 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:13.307374 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.042s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.308003 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:13.461918 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.154s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":573,"lbm_read_time_us":10728,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26203,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:13.462462 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=11.118625
I20260812 06:19:13.507500 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.045s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19563,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.508078 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.518636 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.519109 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.532888 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4941,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.533485 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:13.712416 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.179s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":10651,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26367,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:13.712986 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:13.761976 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.049s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17211,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.762583 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.773499 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.774175 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:13.930585 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.156s	user 0.089s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":10096,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28835,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:19:13.931114 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=11.118625
I20260812 06:19:13.973018 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.042s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16509,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.973587 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.984143 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.984609 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:13.997566 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4745,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.998093 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:14.147280 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.149s	user 0.113s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":632,"lbm_read_time_us":12133,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27145,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:19:14.148072 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=11.118625
I20260812 06:19:14.184671 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15438,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.185377 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:14.208578 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4977,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.209165 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:14.219460 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.220163 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:14.253844 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1077,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1803,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:14.254714 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): free 128867416 bytes of WAL
I20260812 06:19:14.254993 32082 log_reader.cc:385] T f5b95731e2a144c6a0243de6ae3ec6d5: removed 13 log segments from log reader
I20260812 06:19:14.255048 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000015 (ops 72-76)
I20260812 06:19:14.255087 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000016 (ops 77-80)
I20260812 06:19:14.255120 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000017 (ops 81-85)
I20260812 06:19:14.255151 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000018 (ops 86-90)
I20260812 06:19:14.255180 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000019 (ops 91-95)
I20260812 06:19:14.255211 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000020 (ops 96-100)
I20260812 06:19:14.255242 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000021 (ops 101-105)
I20260812 06:19:14.255267 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000022 (ops 106-110)
I20260812 06:19:14.255298 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000023 (ops 111-114)
I20260812 06:19:14.255330 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000024 (ops 115-119)
I20260812 06:19:14.255362 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000025 (ops 120-124)
I20260812 06:19:14.255393 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000026 (ops 125-128)
I20260812 06:19:14.255430 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000027 (ops 129-133)
I20260812 06:19:14.281721 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:14.282246 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): 482 bytes on disk
I20260812 06:19:14.282954 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.283645 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=3.181125
I20260812 06:19:14.298516 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5128264,"delete_count":0,"lbm_write_time_us":5558,"lbm_writes_lt_1ms":128,"reinsert_count":0,"update_count":625}
I20260812 06:19:14.299253 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.196750
I20260812 06:19:14.321725 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.022s	user 0.007s	sys 0.013s Metrics: {"bytes_written":3077030,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:19:14.322317 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:14.558379 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.236s	user 0.158s	sys 0.066s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979837,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1870,"lbm_read_time_us":15094,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37881,"lbm_writes_lt_1ms":743,"mutex_wait_us":1504,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:14.559017 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=18.063937
I20260812 06:19:14.618911 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.060s	user 0.024s	sys 0.032s Metrics: {"bytes_written":20512322,"delete_count":0,"lbm_write_time_us":27832,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:19:14.619776 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:14.633157 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.633579 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:14.849119 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.215s	user 0.137s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":14585,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32290,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":3000}
I20260812 06:19:14.849768 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=18.063937
I20260812 06:19:14.914429 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.064s	user 0.041s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25523,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:14.915016 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:14.931497 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.932082 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:15.126196 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.194s	user 0.128s	sys 0.066s 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":220,"lbm_read_time_us":13140,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34435,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:19:15.127007 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:15.180308 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.049s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21147,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.180941 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:15.194063 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.194510 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:15.362896 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.168s	user 0.116s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":12525,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28128,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:15.363746 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:15.419171 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.055s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17589,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.419842 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:15.436515 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.437094 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:15.593510 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.156s	user 0.114s	sys 0.041s 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":950,"lbm_read_time_us":12702,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":24611,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:15.594028 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=14.095187
I20260812 06:19:15.649931 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.056s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17419,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.650545 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:15.661026 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.661479 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:15.700954 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushMRSOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.039s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":1545,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1397,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:15.701841 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): free 120100640 bytes of WAL
I20260812 06:19:15.702045 32082 log_reader.cc:385] T f5b95731e2a144c6a0243de6ae3ec6d5: removed 12 log segments from log reader
I20260812 06:19:15.702090 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000028 (ops 134-138)
I20260812 06:19:15.702116 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000029 (ops 139-142)
I20260812 06:19:15.702147 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000030 (ops 143-147)
I20260812 06:19:15.702178 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000031 (ops 148-152)
I20260812 06:19:15.702204 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000032 (ops 153-156)
I20260812 06:19:15.702234 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000033 (ops 157-161)
I20260812 06:19:15.702277 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000034 (ops 162-166)
I20260812 06:19:15.702310 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000035 (ops 167-171)
I20260812 06:19:15.702342 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000036 (ops 172-176)
I20260812 06:19:15.702373 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000037 (ops 177-181)
I20260812 06:19:15.702405 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000038 (ops 182-186)
I20260812 06:19:15.702436 32082 log.cc:1079] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: Deleting log segment in path: /tmp/dist-test-taskc87NiU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545839603-31572-0/minicluster-data/ts-0-root/wals/f5b95731e2a144c6a0243de6ae3ec6d5/wal-000000039 (ops 187-190)
I20260812 06:19:15.725455 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: LogGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.023s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:19:15.726022 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5): 463 bytes on disk
I20260812 06:19:15.726455 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: UndoDeltaBlockGCOp(f5b95731e2a144c6a0243de6ae3ec6d5) 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:15.727015 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=3.181125
I20260812 06:19:15.746234 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.019s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:15.746775 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=2.188937
I20260812 06:19:15.756156 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3385,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.756621 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=1.000000
I20260812 06:19:15.878057 31572 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.690s	user 1.745s	sys 0.113s
I20260812 06:19:15.982390 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: MajorDeltaCompactionOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.226s	user 0.142s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1106,"lbm_read_time_us":14942,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38623,"lbm_writes_lt_1ms":743,"mutex_wait_us":400,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":34304,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:19:15.982960 32193 maintenance_manager.cc:419] P 5ee8ba0bb647425fab78151685476dd0: Scheduling FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5): perf score=10.126437
I20260812 06:19:15.992781 31572 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.003s	sys 0.000s
I20260812 06:19:15.993409 31572 tablet_server.cc:179] TabletServer@127.30.213.1:0 shutting down...
I20260812 06:19:16.039582 32082 maintenance_manager.cc:643] P 5ee8ba0bb647425fab78151685476dd0: FlushDeltaMemStoresOp(f5b95731e2a144c6a0243de6ae3ec6d5) complete. Timing: real 0.056s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14513,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.040223 31572 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:16.040436 31572 tablet_replica.cc:333] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0: stopping tablet replica
I20260812 06:19:16.040607 31572 raft_consensus.cc:2243] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.040808 31572 raft_consensus.cc:2272] T f5b95731e2a144c6a0243de6ae3ec6d5 P 5ee8ba0bb647425fab78151685476dd0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.043819 31572 tablet_server.cc:196] TabletServer@127.30.213.1:0 shutdown complete.
I20260812 06:19:16.046530 31572 master.cc:562] Master@127.30.213.62:37147 shutting down...
I20260812 06:19:16.049625 31572 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.049772 31572 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.049827 31572 tablet_replica.cc:333] T 00000000000000000000000000000000 P 006c800eb0e64de1853ab0c209949917: stopping tablet replica
I20260812 06:19:16.061910 31572 master.cc:584] Master@127.30.213.62:37147 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5135 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10290 ms total)

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