[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:00.941274 13905 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.148.126:34515
I20260812 06:20:00.942173 13905 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:00.942720 13905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.948467 13918 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.948606 13905 server_base.cc:1061] running on GCE node
W20260812 06:20:00.948506 13912 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.948709 13915 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.949157 13905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.949257 13905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.949301 13905 hybrid_clock.cc:648] HybridClock initialized: now 1786515600949298 us; error 0 us; skew 500 ppm
I20260812 06:20:00.950826 13905 webserver.cc:533] Webserver started at http://127.13.148.126:43085/ using document root <none> and password file <none>
I20260812 06:20:00.951292 13905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.951349 13905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.951555 13905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.953037 13905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/master-0-root/instance:
uuid: "d7731da0d730417f95cb3b9b71f07a91"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-266d"
I20260812 06:20:00.956156 13905 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:00.958004 13924 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.958904 13905 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:00.959003 13905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/master-0-root
uuid: "d7731da0d730417f95cb3b9b71f07a91"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-266d"
I20260812 06:20:00.959081 13905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.971819 13905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.972309 13905 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:00.972447 13905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.979269 13905 rpc_server.cc:307] RPC server started. Bound to: 127.13.148.126:34515
I20260812 06:20:00.979274 14019 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.148.126:34515 every 8 connection(s)
I20260812 06:20:00.981345 14020 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.986258 14020 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: Bootstrap starting.
I20260812 06:20:00.988386 14020 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.989226 14020 log.cc:826] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:00.990648 14020 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: No bootstrap required, opened a new log
I20260812 06:20:00.993202 14020 raft_consensus.cc:359] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER }
I20260812 06:20:00.993350 14020 raft_consensus.cc:385] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.993412 14020 raft_consensus.cc:740] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d7731da0d730417f95cb3b9b71f07a91, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.993927 14020 consensus_queue.cc:260] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [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: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER }
I20260812 06:20:00.994074 14020 raft_consensus.cc:399] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.994135 14020 raft_consensus.cc:493] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.994246 14020 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.994917 14020 raft_consensus.cc:515] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER }
I20260812 06:20:00.995299 14020 leader_election.cc:304] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [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: d7731da0d730417f95cb3b9b71f07a91; no voters: 
I20260812 06:20:00.995566 14020 leader_election.cc:290] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.995689 14023 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.995898 14023 raft_consensus.cc:697] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 1 LEADER]: Becoming Leader. State: Replica: d7731da0d730417f95cb3b9b71f07a91, State: Running, Role: LEADER
I20260812 06:20:00.996244 14023 consensus_queue.cc:237] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [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: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER }
I20260812 06:20:00.996376 14020 sys_catalog.cc:565] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.997972 14025 sys_catalog.cc:455] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d7731da0d730417f95cb3b9b71f07a91. Latest consensus state: current_term: 1 leader_uuid: "d7731da0d730417f95cb3b9b71f07a91" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER } }
I20260812 06:20:00.998009 14024 sys_catalog.cc:455] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d7731da0d730417f95cb3b9b71f07a91" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7731da0d730417f95cb3b9b71f07a91" member_type: VOTER } }
I20260812 06:20:00.998080 14025 sys_catalog.cc:458] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.998106 14024 sys_catalog.cc:458] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.998497 14041 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.998566 13905 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:01.000555 14041 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:01.004747 14041 catalog_manager.cc:1383] Generated new cluster ID: 5a93d4e97d2748878f1d0d716ed86490
I20260812 06:20:01.004809 14041 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:01.025460 14041 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:01.026293 14041 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:01.034530 14041 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: Generated new TSK 0
I20260812 06:20:01.035115 14041 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:01.063293 13905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:01.065866 14059 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:01.065837 14053 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:01.066094 14055 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:01.066167 13905 server_base.cc:1061] running on GCE node
I20260812 06:20:01.066346 13905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:01.066390 13905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:01.066402 13905 hybrid_clock.cc:648] HybridClock initialized: now 1786515601066403 us; error 0 us; skew 500 ppm
I20260812 06:20:01.067253 13905 webserver.cc:533] Webserver started at http://127.13.148.65:32923/ using document root <none> and password file <none>
I20260812 06:20:01.067399 13905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:01.067447 13905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:01.067526 13905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:01.067907 13905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/instance:
uuid: "95f0595dce7f4cc5bc6f47eba3425e7f"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-266d"
I20260812 06:20:01.069327 13905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:01.070254 14069 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.070510 13905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:01.070581 13905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root
uuid: "95f0595dce7f4cc5bc6f47eba3425e7f"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-266d"
I20260812 06:20:01.070647 13905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:01.080641 13905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:01.080992 13905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:01.081434 13905 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:01.082226 13905 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:01.082278 13905 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.082320 13905 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:01.082350 13905 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.088491 13905 rpc_server.cc:307] RPC server started. Bound to: 127.13.148.65:36013
I20260812 06:20:01.088536 14171 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.148.65:36013 every 8 connection(s)
I20260812 06:20:01.101527 14172 heartbeater.cc:344] Connected to a master server at 127.13.148.126:34515
I20260812 06:20:01.101747 14172 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:01.102124 14172 heartbeater.cc:507] Master 127.13.148.126:34515 requested a full tablet report, sending...
I20260812 06:20:01.103370 13957 ts_manager.cc:194] Registered new tserver with Master: 95f0595dce7f4cc5bc6f47eba3425e7f (127.13.148.65:36013)
I20260812 06:20:01.103482 13905 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014406621s
I20260812 06:20:01.104465 13957 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46746
I20260812 06:20:01.112744 13957 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46760:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:01.126390 14113 tablet_service.cc:1511] Processing CreateTablet for tablet a30309b7f74b49bfb1f630625183b8d4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=97d1dacd79294a42a2f4bdcf6cfb5e08]), partition=
I20260812 06:20:01.126776 14113 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a30309b7f74b49bfb1f630625183b8d4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:01.128958 14193 tablet_bootstrap.cc:492] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Bootstrap starting.
I20260812 06:20:01.129894 14193 tablet_bootstrap.cc:654] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:01.131196 14193 tablet_bootstrap.cc:492] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: No bootstrap required, opened a new log
I20260812 06:20:01.131287 14193 ts_tablet_manager.cc:1403] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:01.131804 14193 raft_consensus.cc:359] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "95f0595dce7f4cc5bc6f47eba3425e7f" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 36013 } }
I20260812 06:20:01.131916 14193 raft_consensus.cc:385] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:01.131995 14193 raft_consensus.cc:740] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 95f0595dce7f4cc5bc6f47eba3425e7f, State: Initialized, Role: FOLLOWER
I20260812 06:20:01.132138 14193 consensus_queue.cc:260] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [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: "95f0595dce7f4cc5bc6f47eba3425e7f" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 36013 } }
I20260812 06:20:01.132216 14193 raft_consensus.cc:399] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:01.132242 14193 raft_consensus.cc:493] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:01.132287 14193 raft_consensus.cc:3060] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:01.132968 14193 raft_consensus.cc:515] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "95f0595dce7f4cc5bc6f47eba3425e7f" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 36013 } }
I20260812 06:20:01.133118 14193 leader_election.cc:304] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [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: 95f0595dce7f4cc5bc6f47eba3425e7f; no voters: 
I20260812 06:20:01.133306 14193 leader_election.cc:290] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:01.133410 14197 raft_consensus.cc:2804] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:01.133625 14197 raft_consensus.cc:697] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 1 LEADER]: Becoming Leader. State: Replica: 95f0595dce7f4cc5bc6f47eba3425e7f, State: Running, Role: LEADER
I20260812 06:20:01.133667 14193 ts_tablet_manager.cc:1434] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:01.133826 14197 consensus_queue.cc:237] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [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: "95f0595dce7f4cc5bc6f47eba3425e7f" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 36013 } }
I20260812 06:20:01.133994 14172 heartbeater.cc:499] Master 127.13.148.126:34515 was elected leader, sending a full tablet report...
I20260812 06:20:01.136325 13957 catalog_manager.cc:5719] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f reported cstate change: term changed from 0 to 1, leader changed from <none> to 95f0595dce7f4cc5bc6f47eba3425e7f (127.13.148.65). New cstate: current_term: 1 leader_uuid: "95f0595dce7f4cc5bc6f47eba3425e7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "95f0595dce7f4cc5bc6f47eba3425e7f" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 36013 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:01.190749 13905 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.009s	sys 0.013s
I20260812 06:20:01.339479 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4): perf score=23.023690
I20260812 06:20:01.515326 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.176s	user 0.141s	sys 0.023s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":218,"delete_count":0,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":809,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42602,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":119,"threads_started":1,"update_count":1500}
I20260812 06:20:01.516546 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling LogGCOp(a30309b7f74b49bfb1f630625183b8d4): free 20743880 bytes of WAL
I20260812 06:20:01.516888 14077 log_reader.cc:385] T a30309b7f74b49bfb1f630625183b8d4: removed 2 log segments from log reader
I20260812 06:20:01.516964 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000001 (ops 1-6)
I20260812 06:20:01.517110 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000002 (ops 7-11)
I20260812 06:20:01.522061 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: LogGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:01.522399 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:01.537235 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.537717 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:01.672565 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.135s	user 0.092s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":738,"lbm_read_time_us":7931,"lbm_reads_lt_1ms":468,"lbm_write_time_us":20935,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":276,"threads_started":5,"update_count":2000}
I20260812 06:20:01.673130 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:01.720985 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.048s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15666,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.721421 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:01.731019 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.731492 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4): 20513816 bytes on disk
I20260812 06:20:01.732197 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.732743 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:01.849704 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.117s	user 0.105s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":525,"lbm_read_time_us":8988,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21966,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:01.850302 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:01.888720 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14076,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.889257 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:01.899945 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.900493 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:02.014858 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.114s	user 0.089s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":544,"lbm_read_time_us":7958,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20478,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:20:02.015492 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:02.057996 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.042s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17670,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.058605 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:02.076165 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.076742 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:02.219553 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.143s	user 0.099s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":9402,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23524,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.220047 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:02.275990 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.056s	user 0.019s	sys 0.034s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24558,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.276571 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:02.293793 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.294253 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:02.464598 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.170s	user 0.119s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":762,"lbm_read_time_us":12227,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24690,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:20:02.465250 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:02.516078 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.051s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21509,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.516640 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:02.527938 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.528434 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:02.682590 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.154s	user 0.119s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":143,"lbm_read_time_us":12285,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27975,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:02.683053 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:02.728571 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.045s	user 0.035s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19778,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.728988 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:02.738672 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.739158 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:02.768926 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1246,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1401,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:02.769694 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling LogGCOp(a30309b7f74b49bfb1f630625183b8d4): free 133024356 bytes of WAL
I20260812 06:20:02.769903 14077 log_reader.cc:385] T a30309b7f74b49bfb1f630625183b8d4: removed 13 log segments from log reader
I20260812 06:20:02.769944 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000003 (ops 12-16)
I20260812 06:20:02.769972 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000004 (ops 17-21)
I20260812 06:20:02.770005 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000005 (ops 22-26)
I20260812 06:20:02.770052 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000006 (ops 27-30)
I20260812 06:20:02.770085 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000007 (ops 31-35)
I20260812 06:20:02.770114 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000008 (ops 36-40)
I20260812 06:20:02.770145 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000009 (ops 41-45)
I20260812 06:20:02.770175 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000010 (ops 46-50)
I20260812 06:20:02.770205 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000011 (ops 51-55)
I20260812 06:20:02.770236 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000012 (ops 56-60)
I20260812 06:20:02.770265 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000013 (ops 61-65)
I20260812 06:20:02.770296 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000014 (ops 66-70)
I20260812 06:20:02.770326 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000015 (ops 71-75)
I20260812 06:20:02.794219 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: LogGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:02.794617 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=4.173312
I20260812 06:20:02.809896 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":5620560,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:20:02.810297 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.196750
I20260812 06:20:02.827750 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:20:02.828240 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:03.028298 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.200s	user 0.123s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020712,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":906,"lbm_read_time_us":13766,"lbm_reads_lt_1ms":766,"lbm_write_time_us":32305,"lbm_writes_lt_1ms":743,"mutex_wait_us":301,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:03.028927 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:03.086884 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.057s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409952,"delete_count":0,"lbm_write_time_us":23688,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.087368 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=3.181125
I20260812 06:20:03.098439 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:03.098860 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:03.108072 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3499,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.108518 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4): 483 bytes on disk
I20260812 06:20:03.108896 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4) 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:20:03.109432 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:03.294047 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.184s	user 0.108s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918251,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":835,"lbm_read_time_us":13336,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29189,"lbm_writes_lt_1ms":643,"mutex_wait_us":293,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:03.294637 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:03.341224 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.046s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.341677 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:03.351150 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.351591 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:03.523479 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.172s	user 0.106s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":11922,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29275,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":78848,"update_count":2500}
I20260812 06:20:03.524068 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:03.577313 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.053s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18820,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:03.577864 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:03.587410 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.587857 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:03.744022 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.156s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":908,"lbm_read_time_us":10999,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27156,"lbm_writes_lt_1ms":543,"mutex_wait_us":254,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.744508 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=11.118625
I20260812 06:20:03.779702 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.035s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14671,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.780278 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:03.796846 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.797355 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:03.938997 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.142s	user 0.100s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":9198,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21797,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:20:03.939498 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=11.118625
I20260812 06:20:03.972808 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.033s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13594,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.973351 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:03.984608 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.985069 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.119997 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.135s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":901,"lbm_read_time_us":7880,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26534,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:04.120596 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:04.158878 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.038s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13262,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.159441 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:04.169059 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.169571 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.202142 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.032s	user 0.024s	sys 0.007s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":152,"dirs.run_wall_time_us":1146,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1624,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:04.202800 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling LogGCOp(a30309b7f74b49bfb1f630625183b8d4): free 116849543 bytes of WAL
I20260812 06:20:04.203003 14077 log_reader.cc:385] T a30309b7f74b49bfb1f630625183b8d4: removed 12 log segments from log reader
I20260812 06:20:04.203056 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000016 (ops 76-80)
I20260812 06:20:04.203085 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000017 (ops 81-85)
I20260812 06:20:04.203118 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000018 (ops 86-90)
I20260812 06:20:04.203148 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000019 (ops 91-94)
I20260812 06:20:04.203181 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000020 (ops 95-99)
I20260812 06:20:04.203212 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000021 (ops 100-104)
I20260812 06:20:04.203243 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000022 (ops 105-108)
I20260812 06:20:04.203274 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000023 (ops 109-113)
I20260812 06:20:04.203305 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000024 (ops 114-118)
I20260812 06:20:04.203334 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000025 (ops 119-122)
I20260812 06:20:04.203364 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000026 (ops 123-127)
I20260812 06:20:04.203394 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000027 (ops 128-132)
I20260812 06:20:04.223063 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: LogGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:04.223424 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=3.181125
I20260812 06:20:04.237062 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.013s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4471875,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:20:04.237743 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4): 472 bytes on disk
I20260812 06:20:04.238169 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.238652 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:04.252058 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4773,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:04.252540 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.414327 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.162s	user 0.116s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2406,"lbm_read_time_us":10795,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32795,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":73984,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:20:04.414824 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:04.464807 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.050s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.465329 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:04.480127 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.480585 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.649233 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.168s	user 0.109s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":11563,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30499,"lbm_writes_lt_1ms":543,"mutex_wait_us":15,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:20:04.649732 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=14.095187
I20260812 06:20:04.689468 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.040s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17456,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.689954 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.825471 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.135s	user 0.114s	sys 0.021s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":582,"lbm_read_time_us":10324,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22158,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:20:04.825984 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=11.118625
I20260812 06:20:04.853763 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.028s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":11399,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:04.854264 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:04.868507 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4839,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.869014 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:04.983268 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.114s	user 0.080s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":75,"lbm_read_time_us":6972,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21263,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.983942 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:05.011476 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11611,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.011926 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:05.023397 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.023823 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:05.145277 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.121s	user 0.105s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":6833,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23895,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.145910 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:05.183463 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.037s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13347,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.183928 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:05.193333 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.193691 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:05.311949 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.118s	user 0.086s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1099,"lbm_read_time_us":8045,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23038,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:20:05.312466 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:05.354023 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.041s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14733,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.354493 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:05.364126 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.364487 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:05.502313 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.138s	user 0.100s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":129,"lbm_read_time_us":9631,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22787,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.502811 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=10.126437
I20260812 06:20:05.543581 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.041s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14297,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.544070 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:05.553942 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.554431 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:05.580608 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushMRSOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.026s	user 0.023s	sys 0.002s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1146,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1471,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:05.581347 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling LogGCOp(a30309b7f74b49bfb1f630625183b8d4): free 133024648 bytes of WAL
I20260812 06:20:05.581554 14077 log_reader.cc:385] T a30309b7f74b49bfb1f630625183b8d4: removed 13 log segments from log reader
I20260812 06:20:05.581602 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000028 (ops 133-137)
I20260812 06:20:05.581629 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000029 (ops 138-142)
I20260812 06:20:05.581660 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000030 (ops 143-147)
I20260812 06:20:05.581691 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000031 (ops 148-152)
I20260812 06:20:05.581722 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000032 (ops 153-157)
I20260812 06:20:05.581754 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000033 (ops 158-162)
I20260812 06:20:05.581786 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000034 (ops 163-166)
I20260812 06:20:05.581817 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000035 (ops 167-171)
I20260812 06:20:05.581847 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000036 (ops 172-176)
I20260812 06:20:05.581877 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000037 (ops 177-181)
I20260812 06:20:05.581907 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000038 (ops 182-186)
I20260812 06:20:05.581938 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000039 (ops 187-191)
I20260812 06:20:05.581967 14077 log.cc:1079] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/a30309b7f74b49bfb1f630625183b8d4/wal-000000040 (ops 192-196)
I20260812 06:20:05.606050 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: LogGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:05.606532 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=3.181125
I20260812 06:20:05.626271 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.020s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:05.626680 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4): 482 bytes on disk
I20260812 06:20:05.627050 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: UndoDeltaBlockGCOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.627552 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4): perf score=2.188937
I20260812 06:20:05.636452 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: FlushDeltaMemStoresOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3293,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.636849 14173 maintenance_manager.cc:419] P 95f0595dce7f4cc5bc6f47eba3425e7f: Scheduling MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4): perf score=1.000000
I20260812 06:20:05.687975 13905 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.497s	user 1.643s	sys 0.147s
I20260812 06:20:05.781944 13905 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.003s	sys 0.000s
I20260812 06:20:05.782536 13905 tablet_server.cc:179] TabletServer@127.13.148.65:0 shutting down...
I20260812 06:20:05.810024 14077 maintenance_manager.cc:643] P 95f0595dce7f4cc5bc6f47eba3425e7f: MajorDeltaCompactionOp(a30309b7f74b49bfb1f630625183b8d4) complete. Timing: real 0.173s	user 0.097s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":187,"lbm_read_time_us":12974,"lbm_reads_lt_1ms":670,"lbm_write_time_us":26485,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":70016,"thread_start_us":60,"threads_started":1,"update_count":3000}
I20260812 06:20:05.810722 13905 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.811178 13905 tablet_replica.cc:333] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f: stopping tablet replica
I20260812 06:20:05.811388 13905 raft_consensus.cc:2243] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.811614 13905 raft_consensus.cc:2272] T a30309b7f74b49bfb1f630625183b8d4 P 95f0595dce7f4cc5bc6f47eba3425e7f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.826918 13905 tablet_server.cc:196] TabletServer@127.13.148.65:0 shutdown complete.
I20260812 06:20:05.861716 13905 master.cc:562] Master@127.13.148.126:34515 shutting down...
I20260812 06:20:05.865113 13905 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.865298 13905 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.865377 13905 tablet_replica.cc:333] T 00000000000000000000000000000000 P d7731da0d730417f95cb3b9b71f07a91: stopping tablet replica
I20260812 06:20:05.877445 13905 master.cc:584] Master@127.13.148.126:34515 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5006 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:05.959059 13905 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.148.126:34831
I20260812 06:20:05.959441 13905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:05.961349 14226 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:05.961422 14231 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:05.961385 13905 server_base.cc:1061] running on GCE node
W20260812 06:20:05.961357 14228 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:05.961712 13905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:05.961755 13905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:05.961773 13905 hybrid_clock.cc:648] HybridClock initialized: now 1786515605961773 us; error 0 us; skew 500 ppm
I20260812 06:20:05.962494 13905 webserver.cc:533] Webserver started at http://127.13.148.126:45913/ using document root <none> and password file <none>
I20260812 06:20:05.962656 13905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:05.962702 13905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:05.962777 13905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:05.963136 13905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/master-0-root/instance:
uuid: "b36dc998130141d1999b27f2d292e19e"
format_stamp: "Formatted at 2026-08-12 06:20:05 on dist-test-slave-266d"
I20260812 06:20:05.964488 13905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:05.965349 14240 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:05.965554 13905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:05.965621 13905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/master-0-root
uuid: "b36dc998130141d1999b27f2d292e19e"
format_stamp: "Formatted at 2026-08-12 06:20:05 on dist-test-slave-266d"
I20260812 06:20:05.965684 13905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:05.993314 13905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:05.993690 13905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:05.997507 13905 rpc_server.cc:307] RPC server started. Bound to: 127.13.148.126:34831
I20260812 06:20:05.999604 14328 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.148.126:34831 every 8 connection(s)
I20260812 06:20:06.000113 14330 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.001912 14330 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e: Bootstrap starting.
I20260812 06:20:06.002723 14330 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.003633 14330 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e: No bootstrap required, opened a new log
I20260812 06:20:06.003989 14330 raft_consensus.cc:359] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER }
I20260812 06:20:06.004073 14330 raft_consensus.cc:385] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.004101 14330 raft_consensus.cc:740] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b36dc998130141d1999b27f2d292e19e, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.004210 14330 consensus_queue.cc:260] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [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: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER }
I20260812 06:20:06.004303 14330 raft_consensus.cc:399] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.004334 14330 raft_consensus.cc:493] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.004370 14330 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.004973 14330 raft_consensus.cc:515] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER }
I20260812 06:20:06.005112 14330 leader_election.cc:304] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [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: b36dc998130141d1999b27f2d292e19e; no voters: 
I20260812 06:20:06.005290 14330 leader_election.cc:290] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.005395 14333 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.005594 14333 raft_consensus.cc:697] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 1 LEADER]: Becoming Leader. State: Replica: b36dc998130141d1999b27f2d292e19e, State: Running, Role: LEADER
I20260812 06:20:06.005725 14333 consensus_queue.cc:237] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [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: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER }
I20260812 06:20:06.005721 14330 sys_catalog.cc:565] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.006153 14337 sys_catalog.cc:455] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [sys.catalog]: SysCatalogTable state changed. Reason: New leader b36dc998130141d1999b27f2d292e19e. Latest consensus state: current_term: 1 leader_uuid: "b36dc998130141d1999b27f2d292e19e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER } }
I20260812 06:20:06.006246 14337 sys_catalog.cc:458] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.006140 14335 sys_catalog.cc:455] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b36dc998130141d1999b27f2d292e19e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b36dc998130141d1999b27f2d292e19e" member_type: VOTER } }
I20260812 06:20:06.006331 14335 sys_catalog.cc:458] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.006546 14340 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.007328 14340 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.007599 13905 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.008991 14340 catalog_manager.cc:1383] Generated new cluster ID: b90b45f003e54acaa4b568ad0618af1d
I20260812 06:20:06.009040 14340 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.017212 14340 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.017702 14340 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.028301 14340 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e: Generated new TSK 0
I20260812 06:20:06.028446 14340 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.039669 13905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.041322 14361 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.041385 14364 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.041414 14367 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.041571 13905 server_base.cc:1061] running on GCE node
I20260812 06:20:06.041803 13905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.041857 13905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:06.041875 13905 hybrid_clock.cc:648] HybridClock initialized: now 1786515606041874 us; error 0 us; skew 500 ppm
I20260812 06:20:06.042637 13905 webserver.cc:533] Webserver started at http://127.13.148.65:42331/ using document root <none> and password file <none>
I20260812 06:20:06.042788 13905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.042836 13905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.042909 13905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.043263 13905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/instance:
uuid: "1c9c9709ba694f7aa16dcc74fcfde794"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-266d"
I20260812 06:20:06.044610 13905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.045473 14373 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.045660 13905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:20:06.045722 13905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root
uuid: "1c9c9709ba694f7aa16dcc74fcfde794"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-266d"
I20260812 06:20:06.045783 13905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:06.069563 13905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.069892 13905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.070165 13905 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.070613 13905 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.070649 13905 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.070681 13905 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.070709 13905 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.074802 13905 rpc_server.cc:307] RPC server started. Bound to: 127.13.148.65:42081
I20260812 06:20:06.076444 14487 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.148.65:42081 every 8 connection(s)
I20260812 06:20:06.080494 14489 heartbeater.cc:344] Connected to a master server at 127.13.148.126:34831
I20260812 06:20:06.080585 14489 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.080752 14489 heartbeater.cc:507] Master 127.13.148.126:34831 requested a full tablet report, sending...
I20260812 06:20:06.081372 14268 ts_manager.cc:194] Registered new tserver with Master: 1c9c9709ba694f7aa16dcc74fcfde794 (127.13.148.65:42081)
I20260812 06:20:06.082069 14268 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32992
I20260812 06:20:06.082099 13905 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00663018s
I20260812 06:20:06.088305 14268 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33002:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:06.096050 14422 tablet_service.cc:1511] Processing CreateTablet for tablet 79c7930124e647b385be4bec4e8550b3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d3475e640fb449f9bb8ab7817bfebb13]), partition=
I20260812 06:20:06.096304 14422 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 79c7930124e647b385be4bec4e8550b3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.098148 14511 tablet_bootstrap.cc:492] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Bootstrap starting.
I20260812 06:20:06.098917 14511 tablet_bootstrap.cc:654] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.099777 14511 tablet_bootstrap.cc:492] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: No bootstrap required, opened a new log
I20260812 06:20:06.099848 14511 ts_tablet_manager.cc:1403] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:06.100172 14511 raft_consensus.cc:359] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c9c9709ba694f7aa16dcc74fcfde794" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 42081 } }
I20260812 06:20:06.100247 14511 raft_consensus.cc:385] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.100281 14511 raft_consensus.cc:740] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c9c9709ba694f7aa16dcc74fcfde794, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.100376 14511 consensus_queue.cc:260] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [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: "1c9c9709ba694f7aa16dcc74fcfde794" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 42081 } }
I20260812 06:20:06.100461 14511 raft_consensus.cc:399] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.100489 14511 raft_consensus.cc:493] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.100522 14511 raft_consensus.cc:3060] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.101171 14511 raft_consensus.cc:515] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c9c9709ba694f7aa16dcc74fcfde794" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 42081 } }
I20260812 06:20:06.101289 14511 leader_election.cc:304] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [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: 1c9c9709ba694f7aa16dcc74fcfde794; no voters: 
I20260812 06:20:06.101475 14511 leader_election.cc:290] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.101579 14514 raft_consensus.cc:2804] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.101784 14514 raft_consensus.cc:697] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 1 LEADER]: Becoming Leader. State: Replica: 1c9c9709ba694f7aa16dcc74fcfde794, State: Running, Role: LEADER
I20260812 06:20:06.101792 14511 ts_tablet_manager.cc:1434] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:06.101982 14489 heartbeater.cc:499] Master 127.13.148.126:34831 was elected leader, sending a full tablet report...
I20260812 06:20:06.101949 14514 consensus_queue.cc:237] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [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: "1c9c9709ba694f7aa16dcc74fcfde794" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 42081 } }
I20260812 06:20:06.103157 14268 catalog_manager.cc:5719] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c9c9709ba694f7aa16dcc74fcfde794 (127.13.148.65). New cstate: current_term: 1 leader_uuid: "1c9c9709ba694f7aa16dcc74fcfde794" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c9c9709ba694f7aa16dcc74fcfde794" member_type: VOTER last_known_addr { host: "127.13.148.65" port: 42081 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.156163 13905 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.008s	sys 0.014s
I20260812 06:20:06.326939 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushMRSOp(79c7930124e647b385be4bec4e8550b3): perf score=23.023690
I20260812 06:20:06.497059 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushMRSOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.170s	user 0.142s	sys 0.024s Metrics: {"bytes_written":15999661,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":35,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":912,"drs_written":1,"lbm_read_time_us":33,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43702,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"update_count":1950}
I20260812 06:20:06.497644 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling LogGCOp(79c7930124e647b385be4bec4e8550b3): free 20743880 bytes of WAL
I20260812 06:20:06.497849 14380 log_reader.cc:385] T 79c7930124e647b385be4bec4e8550b3: removed 2 log segments from log reader
I20260812 06:20:06.497897 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000001 (ops 1-6)
I20260812 06:20:06.497927 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000002 (ops 7-11)
I20260812 06:20:06.502362 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: LogGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:06.502655 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:06.516024 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.516480 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3): 20924073 bytes on disk
I20260812 06:20:06.516921 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.517370 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:06.686264 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.169s	user 0.105s	sys 0.063s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24446413,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":74,"lbm_read_time_us":13260,"lbm_reads_lt_1ms":554,"lbm_write_time_us":24657,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":223,"threads_started":5,"update_count":2450}
I20260812 06:20:06.686702 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:06.742821 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.056s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19319,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.743368 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:06.755365 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.756086 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:06.925642 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.169s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856655,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":646,"lbm_read_time_us":13596,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27197,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:20:06.926071 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:06.972843 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.047s	user 0.033s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.973421 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:06.982985 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.983433 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:07.157959 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.174s	user 0.105s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":14119,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28160,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:07.158649 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:07.211459 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.053s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18799,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.212083 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:07.222944 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.223531 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:07.390630 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.167s	user 0.087s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25424,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:20:07.391086 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:07.432861 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.042s	user 0.016s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17486,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.433406 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:07.456746 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.023s	user 0.005s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.457278 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:07.616430 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.159s	user 0.098s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":10357,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25717,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:20:07.616951 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:07.659153 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.042s	user 0.016s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16036,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.659694 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:07.674496 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.674988 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushMRSOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:07.712517 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushMRSOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.037s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1133,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2050,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:07.713162 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling LogGCOp(79c7930124e647b385be4bec4e8550b3): free 121006425 bytes of WAL
I20260812 06:20:07.713372 14380 log_reader.cc:385] T 79c7930124e647b385be4bec4e8550b3: removed 12 log segments from log reader
I20260812 06:20:07.713419 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000003 (ops 12-16)
I20260812 06:20:07.713445 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000004 (ops 17-20)
I20260812 06:20:07.713474 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000005 (ops 21-25)
I20260812 06:20:07.713505 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000006 (ops 26-30)
I20260812 06:20:07.713536 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000007 (ops 31-35)
I20260812 06:20:07.713569 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000008 (ops 36-40)
I20260812 06:20:07.713601 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000009 (ops 41-45)
I20260812 06:20:07.713632 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000010 (ops 46-50)
I20260812 06:20:07.713665 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000011 (ops 51-55)
I20260812 06:20:07.713697 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000012 (ops 56-60)
I20260812 06:20:07.713729 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000013 (ops 61-65)
I20260812 06:20:07.713761 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000014 (ops 66-70)
I20260812 06:20:07.735639 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: LogGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.022s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:07.736088 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3): 462 bytes on disk
I20260812 06:20:07.736532 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.736986 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:07.758248 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.021s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.758699 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:07.768110 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.768623 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:07.993525 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.225s	user 0.161s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061713,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":398,"lbm_read_time_us":14127,"lbm_reads_lt_1ms":774,"lbm_write_time_us":32118,"lbm_writes_lt_1ms":743,"mutex_wait_us":1,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:20:07.994167 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=18.063937
I20260812 06:20:08.055599 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.061s	user 0.038s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":22970,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:08.056075 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:08.071589 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.072232 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:08.260322 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.188s	user 0.118s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959070,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":816,"lbm_read_time_us":12318,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29331,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":3000}
I20260812 06:20:08.260932 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=16.079562
I20260812 06:20:08.302507 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.041s	user 0.024s	sys 0.015s Metrics: {"bytes_written":17968823,"delete_count":0,"lbm_write_time_us":17837,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:20:08.302912 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=1.196750
I20260812 06:20:08.325410 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.022s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:08.325814 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:08.338702 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4824,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.339179 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:08.533998 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.195s	user 0.113s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959152,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":617,"lbm_read_time_us":13399,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31238,"lbm_writes_lt_1ms":643,"mutex_wait_us":295,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:20:08.534682 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=17.071750
I20260812 06:20:08.582147 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.047s	user 0.023s	sys 0.020s Metrics: {"bytes_written":18953400,"delete_count":0,"lbm_write_time_us":18807,"lbm_writes_lt_1ms":465,"reinsert_count":0,"update_count":2310}
I20260812 06:20:08.582669 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:08.595185 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.012s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1969356,"delete_count":0,"lbm_write_time_us":3139,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:20:08.595688 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:08.605058 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.605463 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:08.795725 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.190s	user 0.126s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959127,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":131,"lbm_read_time_us":12701,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30041,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:20:08.796387 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:08.838532 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.042s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17789,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.839236 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:08.863497 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.863955 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:08.874202 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.874632 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:09.080032 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.205s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959183,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1152,"lbm_read_time_us":12337,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30832,"lbm_writes_lt_1ms":643,"mutex_wait_us":422,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:20:09.080559 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=18.063937
I20260812 06:20:09.140604 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.060s	user 0.031s	sys 0.019s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23889,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.141057 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:09.151528 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.152199 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushMRSOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:09.181021 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushMRSOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1233,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1561,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:09.181748 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling LogGCOp(79c7930124e647b385be4bec4e8550b3): free 136275214 bytes of WAL
I20260812 06:20:09.181994 14380 log_reader.cc:385] T 79c7930124e647b385be4bec4e8550b3: removed 13 log segments from log reader
I20260812 06:20:09.182051 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000015 (ops 71-75)
I20260812 06:20:09.182082 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000016 (ops 76-80)
I20260812 06:20:09.182114 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000017 (ops 81-85)
I20260812 06:20:09.182147 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000018 (ops 86-90)
I20260812 06:20:09.182179 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000019 (ops 91-94)
I20260812 06:20:09.182210 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000020 (ops 95-99)
I20260812 06:20:09.182241 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000021 (ops 100-104)
I20260812 06:20:09.182272 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000022 (ops 105-109)
I20260812 06:20:09.182302 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000023 (ops 110-114)
I20260812 06:20:09.182333 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000024 (ops 115-119)
I20260812 06:20:09.182363 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000025 (ops 120-124)
I20260812 06:20:09.182394 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000026 (ops 125-129)
I20260812 06:20:09.182425 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000027 (ops 130-134)
I20260812 06:20:09.206306 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: LogGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:09.207193 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=4.173312
I20260812 06:20:09.221515 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":5290,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:20:09.221966 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=1.196750
I20260812 06:20:09.231513 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:09.231933 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3): 493 bytes on disk
I20260812 06:20:09.232342 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.232889 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:09.463624 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.231s	user 0.160s	sys 0.068s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37164103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3162,"lbm_read_time_us":17822,"lbm_reads_lt_1ms":874,"lbm_write_time_us":41526,"lbm_writes_lt_1ms":843,"mutex_wait_us":2044,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":116,"threads_started":1,"update_count":4000}
I20260812 06:20:09.464222 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=18.063937
I20260812 06:20:09.521639 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.057s	user 0.044s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24686,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.522213 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=3.181125
I20260812 06:20:09.540205 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.018s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4658,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:09.540673 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:09.553758 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4935,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.554284 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:09.749966 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.195s	user 0.131s	sys 0.064s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33061588,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":66,"lbm_read_time_us":14799,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38528,"lbm_writes_lt_1ms":743,"mutex_wait_us":1,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3500}
I20260812 06:20:09.751187 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:09.797421 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.046s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19768,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.797969 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:09.811031 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.811470 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:09.972302 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.161s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":923,"lbm_read_time_us":10031,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28989,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68224,"update_count":2500}
I20260812 06:20:09.972873 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:10.016726 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.044s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19207,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.017431 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:10.153575 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.136s	user 0.091s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754124,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":326,"lbm_read_time_us":8934,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22301,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:10.154212 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=14.095187
I20260812 06:20:10.205714 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.051s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.206255 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:10.222177 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.222765 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:10.410003 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.187s	user 0.116s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":12969,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29463,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:20:10.410617 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=15.087375
I20260812 06:20:10.448102 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":15789,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:10.448688 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:10.470971 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.022s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:10.471561 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:10.488876 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.017s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":3583,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:20:10.489439 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushMRSOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:10.532449 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushMRSOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.043s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1218,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:10.533304 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling LogGCOp(79c7930124e647b385be4bec4e8550b3): free 121006700 bytes of WAL
I20260812 06:20:10.533571 14380 log_reader.cc:385] T 79c7930124e647b385be4bec4e8550b3: removed 12 log segments from log reader
I20260812 06:20:10.533644 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000028 (ops 135-139)
I20260812 06:20:10.533699 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000029 (ops 140-144)
I20260812 06:20:10.533736 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000030 (ops 145-149)
I20260812 06:20:10.533775 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000031 (ops 150-154)
I20260812 06:20:10.533812 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000032 (ops 155-159)
I20260812 06:20:10.533847 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000033 (ops 160-164)
I20260812 06:20:10.533883 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000034 (ops 165-169)
I20260812 06:20:10.533922 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000035 (ops 170-174)
I20260812 06:20:10.533960 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000036 (ops 175-178)
I20260812 06:20:10.533994 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000037 (ops 179-183)
I20260812 06:20:10.534030 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000038 (ops 184-188)
I20260812 06:20:10.534068 14380 log.cc:1079] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: Deleting log segment in path: /tmp/dist-test-task_VE2Q_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600931223-13905-0/minicluster-data/ts-0-root/wals/79c7930124e647b385be4bec4e8550b3/wal-000000039 (ops 189-193)
I20260812 06:20:10.560322 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: LogGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:10.560848 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=3.181125
I20260812 06:20:10.585330 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5058,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:10.585848 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3): 462 bytes on disk
I20260812 06:20:10.586297 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: UndoDeltaBlockGCOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.586846 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3): perf score=2.188937
I20260812 06:20:10.600198 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: FlushDeltaMemStoresOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.600716 14491 maintenance_manager.cc:419] P 1c9c9709ba694f7aa16dcc74fcfde794: Scheduling MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3): perf score=1.000000
I20260812 06:20:10.686383 13905 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.530s	user 1.682s	sys 0.131s
I20260812 06:20:10.795185 13905 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.001s	sys 0.000s
I20260812 06:20:10.795641 13905 tablet_server.cc:179] TabletServer@127.13.148.65:0 shutting down...
I20260812 06:20:10.833231 14380 maintenance_manager.cc:643] P 1c9c9709ba694f7aa16dcc74fcfde794: MajorDeltaCompactionOp(79c7930124e647b385be4bec4e8550b3) complete. Timing: real 0.232s	user 0.138s	sys 0.093s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37164225,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1410,"lbm_read_time_us":15515,"lbm_reads_lt_1ms":871,"lbm_write_time_us":36602,"lbm_writes_lt_1ms":843,"mutex_wait_us":50,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":92,"threads_started":1,"update_count":4000}
I20260812 06:20:10.834162 13905 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:10.834359 13905 tablet_replica.cc:333] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794: stopping tablet replica
I20260812 06:20:10.834479 13905 raft_consensus.cc:2243] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.834632 13905 raft_consensus.cc:2272] T 79c7930124e647b385be4bec4e8550b3 P 1c9c9709ba694f7aa16dcc74fcfde794 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.839248 13905 tablet_server.cc:196] TabletServer@127.13.148.65:0 shutdown complete.
I20260812 06:20:10.904537 13905 master.cc:562] Master@127.13.148.126:34831 shutting down...
I20260812 06:20:10.907981 13905 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.908155 13905 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.908219 13905 tablet_replica.cc:333] T 00000000000000000000000000000000 P b36dc998130141d1999b27f2d292e19e: stopping tablet replica
I20260812 06:20:10.920198 13905 master.cc:584] Master@127.13.148.126:34831 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5041 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10048 ms total)

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