[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:18.456465 15977 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.154.126:40419
I20260812 06:19:18.457949 15977 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:18.458766 15977 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.469890 15990 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.470145 15994 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.470219 15989 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.470420 15977 server_base.cc:1061] running on GCE node
I20260812 06:19:18.471076 15977 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.471210 15977 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.471254 15977 hybrid_clock.cc:648] HybridClock initialized: now 1786515558471252 us; error 0 us; skew 500 ppm
I20260812 06:19:18.473706 15977 webserver.cc:533] Webserver started at http://127.15.154.126:36379/ using document root <none> and password file <none>
I20260812 06:19:18.474460 15977 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.474546 15977 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.474876 15977 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.477608 15977 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/master-0-root/instance:
uuid: "76d508b3e3ba44ffacd11e8559441438"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-ncp9"
I20260812 06:19:18.483665 15977 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.002s	sys 0.004s
I20260812 06:19:18.486646 16003 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.487880 15977 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:19:18.488030 15977 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/master-0-root
uuid: "76d508b3e3ba44ffacd11e8559441438"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-ncp9"
I20260812 06:19:18.488133 15977 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.504364 15977 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.505136 15977 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:18.505285 15977 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.513309 15977 rpc_server.cc:307] RPC server started. Bound to: 127.15.154.126:40419
I20260812 06:19:18.513319 16098 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.154.126:40419 every 8 connection(s)
I20260812 06:19:18.515723 16100 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.522094 16100 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: Bootstrap starting.
I20260812 06:19:18.524967 16100 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.526016 16100 log.cc:826] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:18.528203 16100 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: No bootstrap required, opened a new log
I20260812 06:19:18.531406 16100 raft_consensus.cc:359] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER }
I20260812 06:19:18.531629 16100 raft_consensus.cc:385] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.531701 16100 raft_consensus.cc:740] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 76d508b3e3ba44ffacd11e8559441438, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.532366 16100 consensus_queue.cc:260] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [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: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER }
I20260812 06:19:18.532542 16100 raft_consensus.cc:399] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.532611 16100 raft_consensus.cc:493] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.532742 16100 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.533670 16100 raft_consensus.cc:515] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER }
I20260812 06:19:18.534176 16100 leader_election.cc:304] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [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: 76d508b3e3ba44ffacd11e8559441438; no voters: 
I20260812 06:19:18.534524 16100 leader_election.cc:290] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.534674 16105 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.534914 16105 raft_consensus.cc:697] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 1 LEADER]: Becoming Leader. State: Replica: 76d508b3e3ba44ffacd11e8559441438, State: Running, Role: LEADER
I20260812 06:19:18.535346 16105 consensus_queue.cc:237] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [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: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER }
I20260812 06:19:18.535588 16100 sys_catalog.cc:565] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.537392 16108 sys_catalog.cc:455] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 76d508b3e3ba44ffacd11e8559441438. Latest consensus state: current_term: 1 leader_uuid: "76d508b3e3ba44ffacd11e8559441438" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER } }
I20260812 06:19:18.537361 16107 sys_catalog.cc:455] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "76d508b3e3ba44ffacd11e8559441438" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76d508b3e3ba44ffacd11e8559441438" member_type: VOTER } }
I20260812 06:19:18.537515 16107 sys_catalog.cc:458] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.537515 16108 sys_catalog.cc:458] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.537890 15977 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.537879 16131 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.540336 16131 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.545003 16131 catalog_manager.cc:1383] Generated new cluster ID: 955181d46e6047e8ae0f2587f3fce808
I20260812 06:19:18.545080 16131 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:18.556269 16131 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:18.557263 16131 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:18.563786 16131 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: Generated new TSK 0
I20260812 06:19:18.564574 16131 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:18.570838 15977 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.574038 16139 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.574187 16140 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.574196 16144 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.574941 15977 server_base.cc:1061] running on GCE node
I20260812 06:19:18.575138 15977 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.575215 15977 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.575243 15977 hybrid_clock.cc:648] HybridClock initialized: now 1786515558575242 us; error 0 us; skew 500 ppm
I20260812 06:19:18.576243 15977 webserver.cc:533] Webserver started at http://127.15.154.65:38105/ using document root <none> and password file <none>
I20260812 06:19:18.576414 15977 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.576474 15977 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.576553 15977 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.576998 15977 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/instance:
uuid: "fc80a066b6d04a52b65ce01424901a9a"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-ncp9"
I20260812 06:19:18.578699 15977 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:18.579756 16154 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.579990 15977 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.580066 15977 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root
uuid: "fc80a066b6d04a52b65ce01424901a9a"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-ncp9"
I20260812 06:19:18.580154 15977 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.587210 15977 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.587719 15977 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.588240 15977 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:18.589200 15977 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:18.589259 15977 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.589322 15977 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:18.589349 15977 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.595892 15977 rpc_server.cc:307] RPC server started. Bound to: 127.15.154.65:43673
I20260812 06:19:18.595920 16266 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.154.65:43673 every 8 connection(s)
I20260812 06:19:18.606906 16267 heartbeater.cc:344] Connected to a master server at 127.15.154.126:40419
I20260812 06:19:18.607170 16267 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:18.607645 16267 heartbeater.cc:507] Master 127.15.154.126:40419 requested a full tablet report, sending...
I20260812 06:19:18.609054 16033 ts_manager.cc:194] Registered new tserver with Master: fc80a066b6d04a52b65ce01424901a9a (127.15.154.65:43673)
I20260812 06:19:18.609153 15977 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012594513s
I20260812 06:19:18.610308 16033 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44402
I20260812 06:19:18.619156 16033 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44418:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:18.637813 16203 tablet_service.cc:1511] Processing CreateTablet for tablet 2c3a9bf12ea845418407890d8844826a (DEFAULT_TABLE table=heavy-update-compaction-test [id=8eec4ab5a6384388b26fea23298a3e42]), partition=
I20260812 06:19:18.638345 16203 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2c3a9bf12ea845418407890d8844826a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.641094 16282 tablet_bootstrap.cc:492] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Bootstrap starting.
I20260812 06:19:18.642318 16282 tablet_bootstrap.cc:654] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.643929 16282 tablet_bootstrap.cc:492] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: No bootstrap required, opened a new log
I20260812 06:19:18.644042 16282 ts_tablet_manager.cc:1403] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:18.644483 16282 raft_consensus.cc:359] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc80a066b6d04a52b65ce01424901a9a" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 43673 } }
I20260812 06:19:18.644593 16282 raft_consensus.cc:385] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.644623 16282 raft_consensus.cc:740] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fc80a066b6d04a52b65ce01424901a9a, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.644801 16282 consensus_queue.cc:260] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [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: "fc80a066b6d04a52b65ce01424901a9a" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 43673 } }
I20260812 06:19:18.644944 16282 raft_consensus.cc:399] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.644994 16282 raft_consensus.cc:493] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.645043 16282 raft_consensus.cc:3060] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.645743 16282 raft_consensus.cc:515] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc80a066b6d04a52b65ce01424901a9a" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 43673 } }
I20260812 06:19:18.645887 16282 leader_election.cc:304] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [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: fc80a066b6d04a52b65ce01424901a9a; no voters: 
I20260812 06:19:18.646104 16282 leader_election.cc:290] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.646271 16284 raft_consensus.cc:2804] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.646515 16282 ts_tablet_manager.cc:1434] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:18.646544 16284 raft_consensus.cc:697] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 1 LEADER]: Becoming Leader. State: Replica: fc80a066b6d04a52b65ce01424901a9a, State: Running, Role: LEADER
I20260812 06:19:18.646757 16267 heartbeater.cc:499] Master 127.15.154.126:40419 was elected leader, sending a full tablet report...
I20260812 06:19:18.646746 16284 consensus_queue.cc:237] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [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: "fc80a066b6d04a52b65ce01424901a9a" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 43673 } }
I20260812 06:19:18.649724 16033 catalog_manager.cc:5719] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a reported cstate change: term changed from 0 to 1, leader changed from <none> to fc80a066b6d04a52b65ce01424901a9a (127.15.154.65). New cstate: current_term: 1 leader_uuid: "fc80a066b6d04a52b65ce01424901a9a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc80a066b6d04a52b65ce01424901a9a" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 43673 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:18.716585 15977 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.018s	sys 0.008s
I20260812 06:19:18.847100 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushMRSOp(2c3a9bf12ea845418407890d8844826a): perf score=15.086190
I20260812 06:19:19.006342 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushMRSOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.159s	user 0.109s	sys 0.045s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":8549,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1225,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39663,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":124,"threads_started":1,"update_count":1450}
I20260812 06:19:19.007665 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling LogGCOp(2c3a9bf12ea845418407890d8844826a): free 20743880 bytes of WAL
I20260812 06:19:19.008023 16163 log_reader.cc:385] T 2c3a9bf12ea845418407890d8844826a: removed 2 log segments from log reader
I20260812 06:19:19.008108 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000001 (ops 1-6)
I20260812 06:19:19.008163 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000002 (ops 7-11)
I20260812 06:19:19.013425 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: LogGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:19.014025 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.029237 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.015s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.029922 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a): 12719217 bytes on disk
I20260812 06:19:19.030612 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.031113 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:19.169504 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.138s	user 0.114s	sys 0.023s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":612,"lbm_read_time_us":9400,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25325,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":319,"threads_started":5,"update_count":1950}
I20260812 06:19:19.170223 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:19.206714 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14369,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.207216 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.218751 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.219641 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:19.347802 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.128s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1505,"lbm_read_time_us":10583,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24361,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:19.348371 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:19.388334 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.040s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17875,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.388875 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.401916 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.402420 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:19.538241 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.136s	user 0.120s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":8935,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29110,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.538777 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:19.589146 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.050s	user 0.027s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17463,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.589813 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.605813 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.606477 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:19.755558 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.149s	user 0.089s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":11731,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24684,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:19:19.756665 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:19.804206 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.047s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15357,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.804721 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.815816 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.816421 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:19.938608 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.122s	user 0.086s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":8568,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23204,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:19.939136 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:19.976708 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.037s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16704,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.977329 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:19.990551 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.991072 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:20.119417 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.128s	user 0.104s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":10342,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24516,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:20.119948 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:20.177340 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.057s	user 0.022s	sys 0.035s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21657,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:20.178129 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:20.190447 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.191054 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:20.337440 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.146s	user 0.086s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":11255,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24703,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:20.338260 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:20.382584 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.044s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20690,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:20.383067 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:20.393772 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.395339 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushMRSOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:20.422468 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushMRSOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1346,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1599,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:20.423305 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling LogGCOp(2c3a9bf12ea845418407890d8844826a): free 128867395 bytes of WAL
I20260812 06:19:20.423542 16163 log_reader.cc:385] T 2c3a9bf12ea845418407890d8844826a: removed 13 log segments from log reader
I20260812 06:19:20.423586 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000003 (ops 12-16)
I20260812 06:19:20.423616 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000004 (ops 17-20)
I20260812 06:19:20.423647 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000005 (ops 21-25)
I20260812 06:19:20.423681 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000006 (ops 26-30)
I20260812 06:19:20.423700 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000007 (ops 31-35)
I20260812 06:19:20.423732 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000008 (ops 36-40)
I20260812 06:19:20.423764 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000009 (ops 41-44)
I20260812 06:19:20.423795 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000010 (ops 45-49)
I20260812 06:19:20.423827 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000011 (ops 50-54)
I20260812 06:19:20.423857 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000012 (ops 55-59)
I20260812 06:19:20.423888 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000013 (ops 60-64)
I20260812 06:19:20.423919 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000014 (ops 65-68)
I20260812 06:19:20.423950 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000015 (ops 69-73)
I20260812 06:19:20.453166 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: LogGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:20.453773 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a): 482 bytes on disk
I20260812 06:19:20.454432 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.455039 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=4.173312
I20260812 06:19:20.481429 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.026s	user 0.012s	sys 0.013s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":7243,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:19:20.481945 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=1.196750
I20260812 06:19:20.489516 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.007s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2472,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:19:20.489964 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:20.692076 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.202s	user 0.127s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877306,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":638,"lbm_read_time_us":14741,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34469,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:20.693660 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=11.118625
I20260812 06:19:20.732517 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.039s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16121,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:20.733227 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:20.755640 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.022s	user 0.009s	sys 0.008s 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:19:20.756498 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:20.906184 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.149s	user 0.101s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":11062,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24534,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.906886 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=11.118625
I20260812 06:19:20.937145 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.030s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13016,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:20.937704 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:20.957736 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.020s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5957,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:20.958289 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.079651 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.121s	user 0.091s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1012,"lbm_read_time_us":7912,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23446,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.080624 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:21.121896 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18404,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.122447 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:21.134238 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.134919 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.260959 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.126s	user 0.108s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":9216,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24460,"lbm_writes_lt_1ms":443,"mutex_wait_us":349,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:21.261417 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:21.309109 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16011,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.309682 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:21.320202 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.320688 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.460228 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.139s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":308,"lbm_read_time_us":10719,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22150,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:21.460737 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:21.502930 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.042s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.503563 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.613997 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.110s	user 0.086s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":575,"lbm_read_time_us":8099,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20827,"lbm_writes_lt_1ms":343,"mutex_wait_us":336,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":43904,"update_count":1500}
I20260812 06:19:21.614563 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:21.655328 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.041s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17555,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.655938 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:21.671721 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.672359 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.803020 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.130s	user 0.118s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":285,"lbm_read_time_us":10692,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23136,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:19:21.803736 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:21.856537 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.053s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15188,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.857230 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:21.870786 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.871327 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushMRSOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:21.922287 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushMRSOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.051s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1555,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1557,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:21.923254 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling LogGCOp(2c3a9bf12ea845418407890d8844826a): free 115943240 bytes of WAL
I20260812 06:19:21.923513 16163 log_reader.cc:385] T 2c3a9bf12ea845418407890d8844826a: removed 11 log segments from log reader
I20260812 06:19:21.923585 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000016 (ops 74-78)
I20260812 06:19:21.923636 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000017 (ops 79-83)
I20260812 06:19:21.923678 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000018 (ops 84-88)
I20260812 06:19:21.923720 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000019 (ops 89-93)
I20260812 06:19:21.923758 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000020 (ops 94-98)
I20260812 06:19:21.923791 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000021 (ops 99-103)
I20260812 06:19:21.923848 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000022 (ops 104-108)
I20260812 06:19:21.923893 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000023 (ops 109-113)
I20260812 06:19:21.923933 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000024 (ops 114-118)
I20260812 06:19:21.923970 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000025 (ops 119-123)
I20260812 06:19:21.924012 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000026 (ops 124-128)
I20260812 06:19:21.954604 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: LogGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:21.955148 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a): 463 bytes on disk
I20260812 06:19:21.955726 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.956313 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=3.181125
I20260812 06:19:21.978231 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.022s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6488,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.978808 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:21.988363 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3456,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.988794 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:22.193113 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.204s	user 0.148s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1332,"lbm_read_time_us":13871,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37182,"lbm_writes_lt_1ms":643,"mutex_wait_us":950,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:22.193691 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=14.095187
I20260812 06:19:22.259442 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.066s	user 0.030s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.259990 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:22.271476 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.272083 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:22.452395 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.180s	user 0.140s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1021,"lbm_read_time_us":12885,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29939,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.452991 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=14.095187
I20260812 06:19:22.514883 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.062s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17692,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.515558 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:22.531136 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.015s	user 0.005s	sys 0.008s 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:19:22.531737 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:22.723881 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.192s	user 0.117s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":687,"lbm_read_time_us":15207,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31613,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.724572 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=14.095187
I20260812 06:19:22.789983 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.065s	user 0.043s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21765,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.790616 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:22.801744 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.802439 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:22.967679 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.165s	user 0.102s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":12173,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29366,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.968319 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=11.118625
I20260812 06:19:23.005645 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.037s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16101,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:23.006397 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:23.021318 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.021901 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:23.195703 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.174s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1111,"lbm_read_time_us":8929,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26151,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:23.196240 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=14.095187
I20260812 06:19:23.250190 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.054s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20987,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.250746 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:23.262251 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.262773 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:23.419435 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.157s	user 0.130s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":12132,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25947,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:23.420089 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=14.095187
I20260812 06:19:23.482087 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.062s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22044,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.482695 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:23.494176 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.494690 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushMRSOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:23.526705 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushMRSOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":373,"dirs.run_wall_time_us":1927,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1923,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:23.527592 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling LogGCOp(2c3a9bf12ea845418407890d8844826a): free 133024644 bytes of WAL
I20260812 06:19:23.527879 16163 log_reader.cc:385] T 2c3a9bf12ea845418407890d8844826a: removed 13 log segments from log reader
I20260812 06:19:23.527937 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000027 (ops 129-133)
I20260812 06:19:23.527992 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000028 (ops 134-138)
I20260812 06:19:23.528131 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000029 (ops 139-143)
I20260812 06:19:23.528162 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000030 (ops 144-148)
I20260812 06:19:23.528195 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000031 (ops 149-153)
I20260812 06:19:23.528231 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000032 (ops 154-158)
I20260812 06:19:23.528266 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000033 (ops 159-163)
I20260812 06:19:23.528298 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000034 (ops 164-168)
I20260812 06:19:23.528329 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000035 (ops 169-173)
I20260812 06:19:23.528360 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000036 (ops 174-178)
I20260812 06:19:23.528532 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000037 (ops 179-182)
I20260812 06:19:23.528585 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000038 (ops 183-187)
I20260812 06:19:23.528620 16163 log.cc:1079] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/2c3a9bf12ea845418407890d8844826a/wal-000000039 (ops 188-192)
I20260812 06:19:23.555889 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: LogGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:23.556385 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=3.181125
I20260812 06:19:23.568279 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4540,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.568917 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=2.188937
I20260812 06:19:23.579059 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3539,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.579741 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a): 482 bytes on disk
I20260812 06:19:23.580370 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: UndoDeltaBlockGCOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.581348 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a): perf score=1.000000
I20260812 06:19:23.704087 15977 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.987s	user 1.763s	sys 0.181s
I20260812 06:19:23.770179 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: MajorDeltaCompactionOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.189s	user 0.134s	sys 0.053s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":12244,"lbm_reads_lt_1ms":770,"lbm_write_time_us":40325,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3500}
I20260812 06:19:23.770732 16268 maintenance_manager.cc:419] P fc80a066b6d04a52b65ce01424901a9a: Scheduling FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a): perf score=10.126437
I20260812 06:19:23.796213 15977 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.091s	user 0.001s	sys 0.000s
I20260812 06:19:23.797099 15977 tablet_server.cc:179] TabletServer@127.15.154.65:0 shutting down...
I20260812 06:19:23.801988 16163 maintenance_manager.cc:643] P fc80a066b6d04a52b65ce01424901a9a: FlushDeltaMemStoresOp(2c3a9bf12ea845418407890d8844826a) complete. Timing: real 0.031s	user 0.010s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13266,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.802675 15977 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:23.803056 15977 tablet_replica.cc:333] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a: stopping tablet replica
I20260812 06:19:23.803298 15977 raft_consensus.cc:2243] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.803542 15977 raft_consensus.cc:2272] T 2c3a9bf12ea845418407890d8844826a P fc80a066b6d04a52b65ce01424901a9a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.818711 15977 tablet_server.cc:196] TabletServer@127.15.154.65:0 shutdown complete.
I20260812 06:19:23.838795 15977 master.cc:562] Master@127.15.154.126:40419 shutting down...
I20260812 06:19:23.842696 15977 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.842904 15977 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.842986 15977 tablet_replica.cc:333] T 00000000000000000000000000000000 P 76d508b3e3ba44ffacd11e8559441438: stopping tablet replica
I20260812 06:19:23.855553 15977 master.cc:584] Master@127.15.154.126:40419 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5486 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:23.942036 15977 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.154.126:38145
I20260812 06:19:23.942437 15977 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:23.945060 16324 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.945360 16321 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.945370 16320 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.945694 15977 server_base.cc:1061] running on GCE node
I20260812 06:19:23.945874 15977 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:23.945920 15977 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:23.945938 15977 hybrid_clock.cc:648] HybridClock initialized: now 1786515563945938 us; error 0 us; skew 500 ppm
I20260812 06:19:23.950352 15977 webserver.cc:533] Webserver started at http://127.15.154.126:39795/ using document root <none> and password file <none>
I20260812 06:19:23.950537 15977 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:23.950593 15977 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:23.950709 15977 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:23.951120 15977 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/master-0-root/instance:
uuid: "3b8011d7961d4b35bdadf64b6b0c422f"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-ncp9"
I20260812 06:19:23.952705 15977 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:23.953764 16334 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.954021 15977 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:23.954128 15977 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/master-0-root
uuid: "3b8011d7961d4b35bdadf64b6b0c422f"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-ncp9"
I20260812 06:19:23.954196 15977 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:23.961856 15977 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:23.962261 15977 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:23.966182 15977 rpc_server.cc:307] RPC server started. Bound to: 127.15.154.126:38145
I20260812 06:19:23.983958 16431 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.154.126:38145 every 8 connection(s)
I20260812 06:19:23.984537 16432 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:23.986496 16432 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f: Bootstrap starting.
I20260812 06:19:23.987272 16432 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:23.988334 16432 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f: No bootstrap required, opened a new log
I20260812 06:19:23.988724 16432 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER }
I20260812 06:19:23.988811 16432 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:23.988839 16432 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3b8011d7961d4b35bdadf64b6b0c422f, State: Initialized, Role: FOLLOWER
I20260812 06:19:23.988986 16432 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [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: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER }
I20260812 06:19:23.989066 16432 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:23.989095 16432 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:23.989130 16432 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:23.989763 16432 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER }
I20260812 06:19:23.989878 16432 leader_election.cc:304] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [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: 3b8011d7961d4b35bdadf64b6b0c422f; no voters: 
I20260812 06:19:23.990039 16432 leader_election.cc:290] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:23.990167 16435 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:23.990374 16435 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 1 LEADER]: Becoming Leader. State: Replica: 3b8011d7961d4b35bdadf64b6b0c422f, State: Running, Role: LEADER
I20260812 06:19:23.990518 16435 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [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: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER }
I20260812 06:19:23.990522 16432 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:23.991000 16439 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3b8011d7961d4b35bdadf64b6b0c422f. Latest consensus state: current_term: 1 leader_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER } }
I20260812 06:19:23.991128 16439 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.990986 16438 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b8011d7961d4b35bdadf64b6b0c422f" member_type: VOTER } }
I20260812 06:19:23.991361 16438 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.991446 16447 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:23.992300 16447 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:23.992578 15977 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:23.994132 16447 catalog_manager.cc:1383] Generated new cluster ID: cb5ee0f8efe24187a054ea72209f83fb
I20260812 06:19:23.994195 16447 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:24.004593 16447 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:24.005218 16447 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:24.014320 16447 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f: Generated new TSK 0
I20260812 06:19:24.014518 16447 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:24.025180 15977 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.027179 16471 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:24.027273 16477 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:24.027346 15977 server_base.cc:1061] running on GCE node
W20260812 06:19:24.027369 16472 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:24.027644 15977 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.027693 15977 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:24.027707 15977 hybrid_clock.cc:648] HybridClock initialized: now 1786515564027707 us; error 0 us; skew 500 ppm
I20260812 06:19:24.028548 15977 webserver.cc:533] Webserver started at http://127.15.154.65:45063/ using document root <none> and password file <none>
I20260812 06:19:24.028703 15977 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.028749 15977 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.028806 15977 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.029222 15977 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/instance:
uuid: "fe90b13758844d988b76674f7a615dca"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-ncp9"
I20260812 06:19:24.030718 15977 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:24.031957 16486 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.032294 15977 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:24.032371 15977 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root
uuid: "fe90b13758844d988b76674f7a615dca"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-ncp9"
I20260812 06:19:24.032449 15977 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:24.042223 15977 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.042651 15977 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:24.042979 15977 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:24.043490 15977 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:24.043536 15977 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.043576 15977 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:24.043603 15977 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.047847 15977 rpc_server.cc:307] RPC server started. Bound to: 127.15.154.65:36687
I20260812 06:19:24.047879 16597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.154.65:36687 every 8 connection(s)
I20260812 06:19:24.055958 16599 heartbeater.cc:344] Connected to a master server at 127.15.154.126:38145
I20260812 06:19:24.056125 16599 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:24.056396 16599 heartbeater.cc:507] Master 127.15.154.126:38145 requested a full tablet report, sending...
I20260812 06:19:24.057216 16362 ts_manager.cc:194] Registered new tserver with Master: fe90b13758844d988b76674f7a615dca (127.15.154.65:36687)
I20260812 06:19:24.057276 15977 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009015979s
I20260812 06:19:24.058234 16362 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51572
I20260812 06:19:24.064759 16362 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51576:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:24.074151 16529 tablet_service.cc:1511] Processing CreateTablet for tablet 40cf06ad5f9a43a6a466b9152d0368f0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=02c6816daa0f4e4fb4c6eddb53ba52c6]), partition=
I20260812 06:19:24.074419 16529 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 40cf06ad5f9a43a6a466b9152d0368f0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:24.077206 16623 tablet_bootstrap.cc:492] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Bootstrap starting.
I20260812 06:19:24.078152 16623 tablet_bootstrap.cc:654] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:24.079331 16623 tablet_bootstrap.cc:492] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: No bootstrap required, opened a new log
I20260812 06:19:24.079430 16623 ts_tablet_manager.cc:1403] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.079950 16623 raft_consensus.cc:359] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe90b13758844d988b76674f7a615dca" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 36687 } }
I20260812 06:19:24.080056 16623 raft_consensus.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:24.080089 16623 raft_consensus.cc:740] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fe90b13758844d988b76674f7a615dca, State: Initialized, Role: FOLLOWER
I20260812 06:19:24.080281 16623 consensus_queue.cc:260] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [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: "fe90b13758844d988b76674f7a615dca" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 36687 } }
I20260812 06:19:24.080375 16623 raft_consensus.cc:399] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:24.080413 16623 raft_consensus.cc:493] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:24.080461 16623 raft_consensus.cc:3060] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.081374 16623 raft_consensus.cc:515] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe90b13758844d988b76674f7a615dca" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 36687 } }
I20260812 06:19:24.081528 16623 leader_election.cc:304] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [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: fe90b13758844d988b76674f7a615dca; no voters: 
I20260812 06:19:24.081753 16623 leader_election.cc:290] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.081893 16625 raft_consensus.cc:2804] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.082090 16623 ts_tablet_manager.cc:1434] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:24.082135 16599 heartbeater.cc:499] Master 127.15.154.126:38145 was elected leader, sending a full tablet report...
I20260812 06:19:24.082137 16625 raft_consensus.cc:697] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 1 LEADER]: Becoming Leader. State: Replica: fe90b13758844d988b76674f7a615dca, State: Running, Role: LEADER
I20260812 06:19:24.082408 16625 consensus_queue.cc:237] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [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: "fe90b13758844d988b76674f7a615dca" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 36687 } }
I20260812 06:19:24.084007 16362 catalog_manager.cc:5719] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca reported cstate change: term changed from 0 to 1, leader changed from <none> to fe90b13758844d988b76674f7a615dca (127.15.154.65). New cstate: current_term: 1 leader_uuid: "fe90b13758844d988b76674f7a615dca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe90b13758844d988b76674f7a615dca" member_type: VOTER last_known_addr { host: "127.15.154.65" port: 36687 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:24.151239 15977 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.015s	sys 0.008s
I20260812 06:19:24.298808 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=15.086190
I20260812 06:19:24.444640 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.146s	user 0.108s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1046,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34551,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:24.445458 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0): free 20743880 bytes of WAL
I20260812 06:19:24.445719 16495 log_reader.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0: removed 2 log segments from log reader
I20260812 06:19:24.445779 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000001 (ops 1-6)
I20260812 06:19:24.445832 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000002 (ops 7-11)
I20260812 06:19:24.451112 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:24.451777 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0): 12719220 bytes on disk
I20260812 06:19:24.452574 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":124,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.453292 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:24.467123 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.467613 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:24.606647 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.139s	user 0.109s	sys 0.030s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":580,"lbm_read_time_us":10477,"lbm_reads_lt_1ms":454,"lbm_write_time_us":23750,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":316,"threads_started":5,"update_count":1950}
I20260812 06:19:24.607275 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:24.651335 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.044s	user 0.022s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16529,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.651923 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:24.667822 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.668926 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:24.797408 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.128s	user 0.092s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":355,"lbm_read_time_us":9227,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24654,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44544,"update_count":2000}
I20260812 06:19:24.797983 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:24.848371 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.050s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15292,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.848927 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:24.859462 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.859947 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.011061 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.151s	user 0.098s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1045,"lbm_read_time_us":11466,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23168,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:19:25.011559 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:25.058560 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.047s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17360,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.059103 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.070426 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.071051 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.214164 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.143s	user 0.094s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":10541,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29049,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25472,"update_count":2000}
I20260812 06:19:25.214769 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:25.253322 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.038s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14237,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.253890 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.265304 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.265930 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.396885 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.131s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":9282,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26827,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:25.397710 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:25.450632 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.053s	user 0.023s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15801,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.451190 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.462374 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.462899 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.613353 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.150s	user 0.095s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":10581,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24444,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.613974 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:25.655440 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.041s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14004,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.656019 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.668836 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.669436 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.800233 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.131s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":781,"lbm_read_time_us":8162,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27312,"lbm_writes_lt_1ms":443,"mutex_wait_us":367,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":736128,"update_count":2000}
I20260812 06:19:25.800979 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:25.852383 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.051s	user 0.023s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23195,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.853046 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.865235 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4484,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.865718 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:25.893872 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1759,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1891,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:25.894532 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0): free 121006437 bytes of WAL
I20260812 06:19:25.894769 16495 log_reader.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0: removed 12 log segments from log reader
I20260812 06:19:25.894815 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000003 (ops 12-16)
I20260812 06:19:25.894845 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000004 (ops 17-20)
I20260812 06:19:25.894878 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000005 (ops 21-25)
I20260812 06:19:25.894909 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000006 (ops 26-30)
I20260812 06:19:25.894941 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000007 (ops 31-35)
I20260812 06:19:25.894981 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000008 (ops 36-40)
I20260812 06:19:25.895001 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000009 (ops 41-45)
I20260812 06:19:25.895032 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000010 (ops 46-50)
I20260812 06:19:25.895064 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000011 (ops 51-55)
I20260812 06:19:25.895097 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000012 (ops 56-60)
I20260812 06:19:25.895128 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000013 (ops 61-65)
I20260812 06:19:25.895161 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000014 (ops 66-70)
I20260812 06:19:25.921463 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:25.921990 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0): 482 bytes on disk
I20260812 06:19:25.922602 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.923197 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=3.181125
I20260812 06:19:25.940448 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6775,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:25.941006 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:25.951231 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.951858 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:26.120864 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.169s	user 0.132s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":600,"lbm_read_time_us":12124,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31233,"lbm_writes_lt_1ms":643,"mutex_wait_us":97,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:26.121656 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=14.095187
I20260812 06:19:26.180187 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.058s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24765,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.180847 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:26.194361 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.194923 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:26.353682 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.159s	user 0.123s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":10388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31167,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:19:26.354419 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=11.118625
I20260812 06:19:26.407289 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.053s	user 0.038s	sys 0.012s Metrics: {"bytes_written":13127976,"delete_count":0,"lbm_write_time_us":21294,"lbm_writes_lt_1ms":323,"reinsert_count":0,"update_count":1600}
I20260812 06:19:26.407953 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:26.419574 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692409,"delete_count":0,"lbm_write_time_us":3898,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.420130 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:26.576094 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.156s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082513,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":310,"lbm_read_time_us":9888,"lbm_reads_lt_1ms":474,"lbm_write_time_us":25135,"lbm_writes_lt_1ms":453,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2050}
I20260812 06:19:26.576735 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=14.095187
I20260812 06:19:26.622766 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.046s	user 0.037s	sys 0.007s Metrics: {"bytes_written":15999661,"delete_count":0,"lbm_write_time_us":21563,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:19:26.623382 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:26.645792 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.646608 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:26.815678 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.169s	user 0.104s	sys 0.064s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364448,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":12284,"lbm_reads_lt_1ms":554,"lbm_write_time_us":27762,"lbm_writes_lt_1ms":533,"mutex_wait_us":48,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2450}
I20260812 06:19:26.816144 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=14.095187
I20260812 06:19:26.863348 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.047s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19051,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.863930 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:26.879971 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.880502 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:27.037364 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.157s	user 0.126s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":804,"lbm_read_time_us":10551,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28163,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:19:27.037935 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=11.118625
I20260812 06:19:27.072662 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.035s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14303,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.073217 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.100456 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.027s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5837,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:19:27.101073 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.115681 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":5218,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:27.116484 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:27.277045 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.160s	user 0.137s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774805,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":289,"lbm_read_time_us":12640,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30226,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:19:27.277683 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=11.118625
I20260812 06:19:27.316658 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":16801,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.317268 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.332602 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5066,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.333182 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:27.373549 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.040s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":121,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1617,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:27.374424 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0): 481 bytes on disk
I20260812 06:19:27.374807 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.375494 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=3.181125
I20260812 06:19:27.387181 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:27.387764 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0): free 128867475 bytes of WAL
I20260812 06:19:27.388029 16495 log_reader.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0: removed 13 log segments from log reader
I20260812 06:19:27.388098 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000015 (ops 71-75)
I20260812 06:19:27.388141 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000016 (ops 76-80)
I20260812 06:19:27.388168 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000017 (ops 81-85)
I20260812 06:19:27.388200 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000018 (ops 86-90)
I20260812 06:19:27.388229 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000019 (ops 91-94)
I20260812 06:19:27.388257 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000020 (ops 95-99)
I20260812 06:19:27.388285 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000021 (ops 100-104)
I20260812 06:19:27.388315 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000022 (ops 105-108)
I20260812 06:19:27.388346 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000023 (ops 109-113)
I20260812 06:19:27.388381 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000024 (ops 114-118)
I20260812 06:19:27.388409 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000025 (ops 119-122)
I20260812 06:19:27.388553 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000026 (ops 123-127)
I20260812 06:19:27.388581 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000027 (ops 128-132)
I20260812 06:19:27.417201 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:27.417657 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.431133 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.431675 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0): free 11564893 bytes of WAL
I20260812 06:19:27.431886 16495 log_reader.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0: removed 1 log segments from log reader
I20260812 06:19:27.431946 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000028 (ops 133-136)
I20260812 06:19:27.434875 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:27.435236 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.462209 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.027s	user 0.012s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5795,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.463538 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:27.705209 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.241s	user 0.152s	sys 0.078s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979850,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3179,"lbm_read_time_us":17897,"lbm_reads_lt_1ms":767,"lbm_write_time_us":37836,"lbm_writes_lt_1ms":743,"mutex_wait_us":1875,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:27.705981 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=18.063937
I20260812 06:19:27.770085 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.064s	user 0.042s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29203,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.770658 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:27.784503 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.785024 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:27.992131 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.207s	user 0.144s	sys 0.062s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":14228,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33628,"lbm_writes_lt_1ms":643,"mutex_wait_us":88,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3000}
I20260812 06:19:27.992749 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=18.063937
I20260812 06:19:28.047627 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.055s	user 0.029s	sys 0.016s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":21577,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:28.048445 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:28.216929 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.168s	user 0.107s	sys 0.060s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774576,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1621,"lbm_read_time_us":12229,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28162,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:19:28.217700 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=14.095187
I20260812 06:19:28.277355 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.059s	user 0.028s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.278102 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:28.297175 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.297838 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:28.491941 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.194s	user 0.142s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":82,"lbm_read_time_us":13675,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28788,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:28.493403 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=14.095187
I20260812 06:19:28.565616 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.068s	user 0.018s	sys 0.047s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.566296 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:28.581369 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.581965 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:28.796847 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.215s	user 0.151s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":86,"lbm_read_time_us":13850,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34089,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:28.797552 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=15.087375
I20260812 06:19:28.851264 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.053s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":22885,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:28.851783 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:28.884064 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.032s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4907,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.884729 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=2.188937
I20260812 06:19:28.899664 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.900449 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:28.944453 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushMRSOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.044s	user 0.032s	sys 0.006s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1971,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:28.945393 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0): free 112692608 bytes of WAL
I20260812 06:19:28.945650 16495 log_reader.cc:385] T 40cf06ad5f9a43a6a466b9152d0368f0: removed 11 log segments from log reader
I20260812 06:19:28.945710 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000029 (ops 137-141)
I20260812 06:19:28.945820 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000030 (ops 142-146)
I20260812 06:19:28.945866 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000031 (ops 147-151)
I20260812 06:19:28.945891 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000032 (ops 152-156)
I20260812 06:19:28.945952 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000033 (ops 157-161)
I20260812 06:19:28.945991 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000034 (ops 162-166)
I20260812 06:19:28.946063 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000035 (ops 167-171)
I20260812 06:19:28.946115 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000036 (ops 172-176)
I20260812 06:19:28.946156 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000037 (ops 177-181)
I20260812 06:19:28.946190 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000038 (ops 182-186)
I20260812 06:19:28.946226 16495 log.cc:1079] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: Deleting log segment in path: /tmp/dist-test-taskUOJtwp/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558441660-15977-0/minicluster-data/ts-0-root/wals/40cf06ad5f9a43a6a466b9152d0368f0/wal-000000039 (ops 187-191)
I20260812 06:19:28.973224 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: LogGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:28.973886 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0): 462 bytes on disk
I20260812 06:19:28.974370 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: UndoDeltaBlockGCOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.975883 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=5.165500
I20260812 06:19:28.991325 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":6400018,"delete_count":0,"lbm_write_time_us":5952,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:19:28.991992 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:29.000137 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2587,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:19:29.000638 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=1.000000
I20260812 06:19:29.131997 15977 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.981s	user 1.778s	sys 0.172s
I20260812 06:19:29.261113 15977 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.129s	user 0.004s	sys 0.000s
I20260812 06:19:29.261845 15977 tablet_server.cc:179] TabletServer@127.15.154.65:0 shutting down...
I20260812 06:19:29.261911 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: MajorDeltaCompactionOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.261s	user 0.170s	sys 0.083s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082218,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3206,"lbm_read_time_us":17550,"lbm_reads_lt_1ms":863,"lbm_write_time_us":44308,"lbm_writes_lt_1ms":843,"mutex_wait_us":1356,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":79,"threads_started":1,"update_count":4000}
I20260812 06:19:29.262554 16600 maintenance_manager.cc:419] P fe90b13758844d988b76674f7a615dca: Scheduling FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0): perf score=10.126437
I20260812 06:19:29.301968 16495 maintenance_manager.cc:643] P fe90b13758844d988b76674f7a615dca: FlushDeltaMemStoresOp(40cf06ad5f9a43a6a466b9152d0368f0) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14662,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.302839 15977 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:29.303218 15977 tablet_replica.cc:333] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca: stopping tablet replica
I20260812 06:19:29.303381 15977 raft_consensus.cc:2243] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.303574 15977 raft_consensus.cc:2272] T 40cf06ad5f9a43a6a466b9152d0368f0 P fe90b13758844d988b76674f7a615dca [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.308531 15977 tablet_server.cc:196] TabletServer@127.15.154.65:0 shutdown complete.
I20260812 06:19:29.331835 15977 master.cc:562] Master@127.15.154.126:38145 shutting down...
I20260812 06:19:29.336081 15977 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.336292 15977 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.336345 15977 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3b8011d7961d4b35bdadf64b6b0c422f: stopping tablet replica
I20260812 06:19:29.349951 15977 master.cc:584] Master@127.15.154.126:38145 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5489 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10977 ms total)

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