[==========] 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:16:38.782972 10489 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.62.126:43323
I20260812 06:16:38.784026 10489 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:16:38.784616 10489 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:38.791096 10494 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:16:38.791096 10497 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:16:38.791317 10489 server_base.cc:1061] running on GCE node
W20260812 06:16:38.791513 10495 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:16:38.792021 10489 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:38.792129 10489 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:16:38.792172 10489 hybrid_clock.cc:648] HybridClock initialized: now 1786515398792170 us; error 0 us; skew 500 ppm
I20260812 06:16:38.793910 10489 webserver.cc:533] Webserver started at http://127.10.62.126:42645/ using document root <none> and password file <none>
I20260812 06:16:38.794428 10489 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:38.794487 10489 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:38.794731 10489 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:38.796434 10489 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/master-0-root/instance:
uuid: "7ae1183034fd47c09137caf419b15060"
format_stamp: "Formatted at 2026-08-12 06:16:38 on dist-test-slave-f7th"
I20260812 06:16:38.799842 10489 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:38.801862 10502 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:16:38.802983 10489 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:38.803097 10489 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/master-0-root
uuid: "7ae1183034fd47c09137caf419b15060"
format_stamp: "Formatted at 2026-08-12 06:16:38 on dist-test-slave-f7th"
I20260812 06:16:38.803189 10489 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-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:16:38.829113 10489 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:38.829747 10489 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:16:38.829911 10489 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:38.837368 10489 rpc_server.cc:307] RPC server started. Bound to: 127.10.62.126:43323
I20260812 06:16:38.837379 10554 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.62.126:43323 every 8 connection(s)
I20260812 06:16:38.839864 10555 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:16:38.846876 10555 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: Bootstrap starting.
I20260812 06:16:38.849648 10555 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:38.850729 10555 log.cc:826] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:38.852706 10555 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: No bootstrap required, opened a new log
I20260812 06:16:38.856277 10555 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ae1183034fd47c09137caf419b15060" member_type: VOTER }
I20260812 06:16:38.856473 10555 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:38.856524 10555 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ae1183034fd47c09137caf419b15060, State: Initialized, Role: FOLLOWER
I20260812 06:16:38.857196 10555 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [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: "7ae1183034fd47c09137caf419b15060" member_type: VOTER }
I20260812 06:16:38.857365 10555 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:38.857424 10555 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:38.857532 10555 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:38.858467 10555 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ae1183034fd47c09137caf419b15060" member_type: VOTER }
I20260812 06:16:38.858965 10555 leader_election.cc:304] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [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: 7ae1183034fd47c09137caf419b15060; no voters: 
I20260812 06:16:38.859305 10555 leader_election.cc:290] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:38.859541 10558 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:38.859830 10558 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 1 LEADER]: Becoming Leader. State: Replica: 7ae1183034fd47c09137caf419b15060, State: Running, Role: LEADER
I20260812 06:16:38.860231 10558 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [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: "7ae1183034fd47c09137caf419b15060" member_type: VOTER }
I20260812 06:16:38.860347 10555 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:38.862062 10560 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7ae1183034fd47c09137caf419b15060. Latest consensus state: current_term: 1 leader_uuid: "7ae1183034fd47c09137caf419b15060" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ae1183034fd47c09137caf419b15060" member_type: VOTER } }
I20260812 06:16:38.862109 10559 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7ae1183034fd47c09137caf419b15060" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ae1183034fd47c09137caf419b15060" member_type: VOTER } }
I20260812 06:16:38.862185 10560 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:38.862185 10559 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:38.862515 10569 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:38.862730 10489 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:38.865082 10569 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:38.869234 10569 catalog_manager.cc:1383] Generated new cluster ID: 906339518c4f41cf857c1b0bd579240a
I20260812 06:16:38.869293 10569 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:38.877432 10569 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:38.878297 10569 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:38.891568 10569 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: Generated new TSK 0
I20260812 06:16:38.892216 10569 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:38.895102 10489 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:38.897761 10577 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:16:38.897884 10580 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:16:38.898034 10578 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:16:38.898149 10489 server_base.cc:1061] running on GCE node
I20260812 06:16:38.898379 10489 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:38.898449 10489 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:16:38.898469 10489 hybrid_clock.cc:648] HybridClock initialized: now 1786515398898469 us; error 0 us; skew 500 ppm
I20260812 06:16:38.899324 10489 webserver.cc:533] Webserver started at http://127.10.62.65:36571/ using document root <none> and password file <none>
I20260812 06:16:38.899492 10489 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:38.899541 10489 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:38.899643 10489 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:38.900003 10489 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/instance:
uuid: "d87da25698424f4ba9fd5b7e23a6c868"
format_stamp: "Formatted at 2026-08-12 06:16:38 on dist-test-slave-f7th"
I20260812 06:16:38.901458 10489 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:38.902345 10585 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:16:38.902570 10489 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:38.902638 10489 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root
uuid: "d87da25698424f4ba9fd5b7e23a6c868"
format_stamp: "Formatted at 2026-08-12 06:16:38 on dist-test-slave-f7th"
I20260812 06:16:38.902714 10489 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-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:16:38.913997 10489 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:38.914408 10489 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:38.914863 10489 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:38.915757 10489 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:38.915814 10489 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:38.915894 10489 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:38.915923 10489 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:38.921959 10489 rpc_server.cc:307] RPC server started. Bound to: 127.10.62.65:37903
I20260812 06:16:38.922014 10648 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.62.65:37903 every 8 connection(s)
I20260812 06:16:38.931758 10649 heartbeater.cc:344] Connected to a master server at 127.10.62.126:43323
I20260812 06:16:38.931988 10649 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:38.932435 10649 heartbeater.cc:507] Master 127.10.62.126:43323 requested a full tablet report, sending...
I20260812 06:16:38.933743 10519 ts_manager.cc:194] Registered new tserver with Master: d87da25698424f4ba9fd5b7e23a6c868 (127.10.62.65:37903)
I20260812 06:16:38.934619 10489 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011973735s
I20260812 06:16:38.935072 10519 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38050
I20260812 06:16:38.944021 10519 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38054:
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:16:38.960321 10613 tablet_service.cc:1511] Processing CreateTablet for tablet 3619b65ec56a4145b16d80699652bad8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a1336e91043a4805a732bc5479af3823]), partition=
I20260812 06:16:38.961093 10613 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3619b65ec56a4145b16d80699652bad8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:38.964718 10661 tablet_bootstrap.cc:492] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Bootstrap starting.
I20260812 06:16:38.966296 10661 tablet_bootstrap.cc:654] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:38.967680 10661 tablet_bootstrap.cc:492] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: No bootstrap required, opened a new log
I20260812 06:16:38.967794 10661 ts_tablet_manager.cc:1403] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:38.968317 10661 raft_consensus.cc:359] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d87da25698424f4ba9fd5b7e23a6c868" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 37903 } }
I20260812 06:16:38.968473 10661 raft_consensus.cc:385] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:38.968508 10661 raft_consensus.cc:740] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d87da25698424f4ba9fd5b7e23a6c868, State: Initialized, Role: FOLLOWER
I20260812 06:16:38.968712 10661 consensus_queue.cc:260] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [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: "d87da25698424f4ba9fd5b7e23a6c868" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 37903 } }
I20260812 06:16:38.968823 10661 raft_consensus.cc:399] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:38.968900 10661 raft_consensus.cc:493] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:38.968966 10661 raft_consensus.cc:3060] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:38.969985 10661 raft_consensus.cc:515] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d87da25698424f4ba9fd5b7e23a6c868" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 37903 } }
I20260812 06:16:38.970191 10661 leader_election.cc:304] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [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: d87da25698424f4ba9fd5b7e23a6c868; no voters: 
I20260812 06:16:38.970606 10661 leader_election.cc:290] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:38.970749 10663 raft_consensus.cc:2804] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:38.970934 10663 raft_consensus.cc:697] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 1 LEADER]: Becoming Leader. State: Replica: d87da25698424f4ba9fd5b7e23a6c868, State: Running, Role: LEADER
I20260812 06:16:38.971014 10661 ts_tablet_manager.cc:1434] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:38.971089 10663 consensus_queue.cc:237] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [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: "d87da25698424f4ba9fd5b7e23a6c868" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 37903 } }
I20260812 06:16:38.971312 10649 heartbeater.cc:499] Master 127.10.62.126:43323 was elected leader, sending a full tablet report...
I20260812 06:16:38.974574 10519 catalog_manager.cc:5719] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 reported cstate change: term changed from 0 to 1, leader changed from <none> to d87da25698424f4ba9fd5b7e23a6c868 (127.10.62.65). New cstate: current_term: 1 leader_uuid: "d87da25698424f4ba9fd5b7e23a6c868" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d87da25698424f4ba9fd5b7e23a6c868" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 37903 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:39.051990 10489 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.028s	sys 0.004s
I20260812 06:16:39.173328 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushMRSOp(3619b65ec56a4145b16d80699652bad8): perf score=15.086190
I20260812 06:16:39.341989 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushMRSOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.168s	user 0.126s	sys 0.031s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":1085,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":8560,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40305,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":117,"threads_started":1,"update_count":1450}
I20260812 06:16:39.343139 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8): 12719221 bytes on disk
I20260812 06:16:39.343781 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.344242 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling LogGCOp(3619b65ec56a4145b16d80699652bad8): free 20743880 bytes of WAL
I20260812 06:16:39.350028 10590 log_reader.cc:385] T 3619b65ec56a4145b16d80699652bad8: removed 2 log segments from log reader
I20260812 06:16:39.350188 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000001 (ops 1-6)
I20260812 06:16:39.350303 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000002 (ops 7-11)
I20260812 06:16:39.355019 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: LogGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:39.355475 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:39.375461 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.020s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.375998 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:39.511067 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.131s	user 0.106s	sys 0.024s 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":1518,"lbm_read_time_us":8013,"lbm_reads_lt_1ms":450,"lbm_write_time_us":26114,"lbm_writes_lt_1ms":433,"mutex_wait_us":800,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":362,"threads_started":5,"update_count":1950}
I20260812 06:16:39.511876 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:39.550464 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.038s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13003,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.550920 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:39.566066 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.566557 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:39.692085 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.125s	user 0.097s	sys 0.027s 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":132,"lbm_read_time_us":7850,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22192,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:39.692549 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:39.730625 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.038s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15608,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.731243 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:39.831851 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.100s	user 0.081s	sys 0.016s 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":1413,"lbm_read_time_us":6088,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17407,"lbm_writes_lt_1ms":343,"mutex_wait_us":1177,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":1500}
I20260812 06:16:39.832357 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:39.866279 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.034s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14889,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.866720 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:39.983004 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.116s	user 0.082s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1058,"lbm_read_time_us":5681,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20626,"lbm_writes_lt_1ms":343,"mutex_wait_us":692,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:16:39.983496 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:40.027664 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17619,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.028174 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:40.043329 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.043880 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:40.182340 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.138s	user 0.096s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":8543,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27938,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.182889 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:40.224154 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.041s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14380,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.224738 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:40.234685 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.235158 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:40.400607 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.165s	user 0.096s	sys 0.055s 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":433,"lbm_read_time_us":10189,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23695,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:16:40.401335 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:40.438297 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.037s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.438927 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:40.547771 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.109s	user 0.090s	sys 0.018s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":289,"lbm_read_time_us":6794,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19416,"lbm_writes_lt_1ms":343,"mutex_wait_us":34,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":1500}
I20260812 06:16:40.548261 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:40.586407 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.038s	user 0.016s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14017,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.586822 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:40.596376 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.596738 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushMRSOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:40.633635 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushMRSOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.037s	user 0.022s	sys 0.006s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1500,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1200,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:40.634639 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling LogGCOp(3619b65ec56a4145b16d80699652bad8): free 112239312 bytes of WAL
I20260812 06:16:40.634884 10590 log_reader.cc:385] T 3619b65ec56a4145b16d80699652bad8: removed 11 log segments from log reader
I20260812 06:16:40.634943 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000003 (ops 12-16)
I20260812 06:16:40.635007 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000004 (ops 17-21)
I20260812 06:16:40.635044 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000005 (ops 22-26)
I20260812 06:16:40.635079 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000006 (ops 27-30)
I20260812 06:16:40.635106 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000007 (ops 31-35)
I20260812 06:16:40.635134 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000008 (ops 36-40)
I20260812 06:16:40.635160 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000009 (ops 41-45)
I20260812 06:16:40.635188 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000010 (ops 46-50)
I20260812 06:16:40.635221 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000011 (ops 51-55)
I20260812 06:16:40.635242 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000012 (ops 56-60)
I20260812 06:16:40.635262 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000013 (ops 61-65)
I20260812 06:16:40.659062 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: LogGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:40.659430 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8): 447 bytes on disk
I20260812 06:16:40.659896 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:16:40.660346 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=3.181125
I20260812 06:16:40.677877 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6300,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:40.678359 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:40.687073 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3070,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:40.687520 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:40.861443 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.174s	user 0.125s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1625,"lbm_read_time_us":12046,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33870,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:16:40.862003 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=11.118625
I20260812 06:16:40.896313 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13904,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:40.896836 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:40.916554 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5739,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:40.917049 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:41.067519 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.150s	user 0.126s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":526,"lbm_read_time_us":6848,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30820,"lbm_writes_lt_1ms":443,"mutex_wait_us":262,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.068233 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=11.118625
I20260812 06:16:41.107726 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.039s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16612,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:41.108343 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:41.123037 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5268,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:41.123517 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:41.264984 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.141s	user 0.084s	sys 0.057s 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":76,"lbm_read_time_us":9739,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23589,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:16:41.265496 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:41.312849 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.047s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14283,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.313279 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:41.323266 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.010s	user 0.001s	sys 0.007s 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:16:41.323771 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:41.460409 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.136s	user 0.101s	sys 0.025s 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":367,"lbm_read_time_us":8433,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23595,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:41.461150 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:41.511963 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.051s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21434,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.512451 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:41.526785 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.527328 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:41.683509 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.156s	user 0.108s	sys 0.033s 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":678,"lbm_read_time_us":9721,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28395,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:41.684074 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=14.095187
I20260812 06:16:41.734045 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.050s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20315,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:16:41.734583 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:41.749606 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.750193 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:41.898592 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.147s	user 0.108s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":523,"lbm_read_time_us":10746,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26185,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:16:41.899281 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:41.937469 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.038s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16591,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.938015 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.050280 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.112s	user 0.088s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":161,"lbm_read_time_us":7556,"lbm_reads_lt_1ms":367,"lbm_write_time_us":17717,"lbm_writes_lt_1ms":343,"mutex_wait_us":60,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":1500}
I20260812 06:16:42.050861 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=7.149875
I20260812 06:16:42.077943 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10932,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:42.078485 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:42.087699 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3376,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.088121 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushMRSOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.122653 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushMRSOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":205,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1207,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1825,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:42.123500 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling LogGCOp(3619b65ec56a4145b16d80699652bad8): free 121006437 bytes of WAL
I20260812 06:16:42.123757 10590 log_reader.cc:385] T 3619b65ec56a4145b16d80699652bad8: removed 12 log segments from log reader
I20260812 06:16:42.123808 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000014 (ops 66-70)
I20260812 06:16:42.123853 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000015 (ops 71-75)
I20260812 06:16:42.123886 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000016 (ops 76-80)
I20260812 06:16:42.123914 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000017 (ops 81-85)
I20260812 06:16:42.123941 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000018 (ops 86-90)
I20260812 06:16:42.123970 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000019 (ops 91-95)
I20260812 06:16:42.124003 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000020 (ops 96-100)
I20260812 06:16:42.124035 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000021 (ops 101-105)
I20260812 06:16:42.124063 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000022 (ops 106-110)
I20260812 06:16:42.124092 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000023 (ops 111-114)
I20260812 06:16:42.124123 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000024 (ops 115-119)
I20260812 06:16:42.124156 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000025 (ops 120-124)
I20260812 06:16:42.148980 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: LogGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:16:42.149379 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=3.181125
I20260812 06:16:42.171101 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.022s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6456,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:42.171636 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:42.183144 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.183743 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.337539 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.154s	user 0.130s	sys 0.020s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24774908,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1613,"lbm_read_time_us":10424,"lbm_reads_lt_1ms":574,"lbm_write_time_us":28947,"lbm_writes_lt_1ms":543,"mutex_wait_us":542,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":111,"threads_started":1,"update_count":2500}
I20260812 06:16:42.338105 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:42.373760 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.033s	user 0.028s	sys 0.001s Metrics: {"bytes_written":12348517,"delete_count":0,"lbm_write_time_us":12509,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1505}
I20260812 06:16:42.374272 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:42.386296 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:16:42.386757 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8): 461 bytes on disk
I20260812 06:16:42.387256 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.387890 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.514304 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.126s	user 0.098s	sys 0.020s 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":261,"lbm_read_time_us":8254,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22152,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:16:42.514842 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:42.566536 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.052s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21604,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.567068 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:42.580514 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.581089 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.708050 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.127s	user 0.083s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":538,"lbm_read_time_us":7608,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23512,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:16:42.708540 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:42.768159 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.057s	user 0.025s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.768721 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:42.781148 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.781644 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:42.938236 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.156s	user 0.122s	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":157,"lbm_read_time_us":10736,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25839,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.938964 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:42.986768 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.048s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15577,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.987298 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.004693 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.017s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.005378 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.136042 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.130s	user 0.121s	sys 0.006s 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":987,"lbm_read_time_us":8314,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25079,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.137149 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:43.176230 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.038s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15994,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.176832 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.191772 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.192209 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.316205 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.124s	user 0.083s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":132,"lbm_read_time_us":7094,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23198,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.316777 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:43.357219 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.040s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14319,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.357669 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.367588 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.368050 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.493593 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.125s	user 0.096s	sys 0.026s 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":328,"lbm_read_time_us":8796,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22887,"lbm_writes_lt_1ms":443,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:43.494151 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:43.540863 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.047s	user 0.028s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16123,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.541368 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.555811 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.014s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.556337 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushMRSOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.590281 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushMRSOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.034s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1609,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1584,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:43.590860 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.724514 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.134s	user 0.088s	sys 0.039s 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":290,"lbm_read_time_us":8382,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21792,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:16:43.725133 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling LogGCOp(3619b65ec56a4145b16d80699652bad8): free 124257489 bytes of WAL
I20260812 06:16:43.725392 10590 log_reader.cc:385] T 3619b65ec56a4145b16d80699652bad8: removed 12 log segments from log reader
I20260812 06:16:43.725492 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000026 (ops 125-129)
I20260812 06:16:43.725576 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000027 (ops 130-134)
I20260812 06:16:43.725642 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000028 (ops 135-138)
I20260812 06:16:43.725708 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000029 (ops 139-143)
I20260812 06:16:43.725772 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000030 (ops 144-148)
I20260812 06:16:43.725836 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000031 (ops 149-153)
I20260812 06:16:43.725909 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000032 (ops 154-158)
I20260812 06:16:43.725983 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000033 (ops 159-163)
I20260812 06:16:43.726046 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000034 (ops 164-168)
I20260812 06:16:43.726109 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000035 (ops 169-173)
I20260812 06:16:43.726181 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000036 (ops 174-178)
I20260812 06:16:43.726244 10590 log.cc:1079] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/3619b65ec56a4145b16d80699652bad8/wal-000000037 (ops 179-183)
I20260812 06:16:43.752728 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: LogGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:16:43.753933 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:43.784875 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.027s	user 0.022s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11523,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:43.785537 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8): 472 bytes on disk
I20260812 06:16:43.786171 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: UndoDeltaBlockGCOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.786949 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.801272 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5071,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:43.801790 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:43.917505 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.116s	user 0.098s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1618,"lbm_read_time_us":9003,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21148,"lbm_writes_lt_1ms":443,"mutex_wait_us":604,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:43.918040 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=10.126437
I20260812 06:16:43.958937 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.041s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16836,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.961530 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8): perf score=2.188937
I20260812 06:16:43.975093 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: FlushDeltaMemStoresOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.975689 10650 maintenance_manager.cc:419] P d87da25698424f4ba9fd5b7e23a6c868: Scheduling MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8): perf score=1.000000
I20260812 06:16:44.000228 10489 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.948s	user 1.813s	sys 0.096s
I20260812 06:16:44.062471 10489 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.004s	sys 0.000s
I20260812 06:16:44.063125 10489 tablet_server.cc:179] TabletServer@127.10.62.65:0 shutting down...
I20260812 06:16:44.091420 10590 maintenance_manager.cc:643] P d87da25698424f4ba9fd5b7e23a6c868: MajorDeltaCompactionOp(3619b65ec56a4145b16d80699652bad8) complete. Timing: real 0.116s	user 0.088s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":662,"lbm_read_time_us":10712,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":467,"lbm_write_time_us":19387,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.092213 10489 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:44.092649 10489 tablet_replica.cc:333] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868: stopping tablet replica
I20260812 06:16:44.092856 10489 raft_consensus.cc:2243] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:44.093088 10489 raft_consensus.cc:2272] T 3619b65ec56a4145b16d80699652bad8 P d87da25698424f4ba9fd5b7e23a6c868 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:44.108878 10489 tablet_server.cc:196] TabletServer@127.10.62.65:0 shutdown complete.
I20260812 06:16:44.130749 10489 master.cc:562] Master@127.10.62.126:43323 shutting down...
I20260812 06:16:44.134238 10489 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:44.134435 10489 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:44.134510 10489 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7ae1183034fd47c09137caf419b15060: stopping tablet replica
I20260812 06:16:44.146981 10489 master.cc:584] Master@127.10.62.126:43323 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5437 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:44.219677 10489 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.62.126:35337
I20260812 06:16:44.220043 10489 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:44.221977 10682 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:16:44.221966 10684 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:16:44.222121 10489 server_base.cc:1061] running on GCE node
W20260812 06:16:44.222193 10681 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:16:44.222380 10489 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:44.222430 10489 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:16:44.222450 10489 hybrid_clock.cc:648] HybridClock initialized: now 1786515404222450 us; error 0 us; skew 500 ppm
I20260812 06:16:44.223207 10489 webserver.cc:533] Webserver started at http://127.10.62.126:39259/ using document root <none> and password file <none>
I20260812 06:16:44.223361 10489 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:44.223415 10489 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:44.223489 10489 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:44.223884 10489 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/master-0-root/instance:
uuid: "52e18c3f44ec447d95aa5ae99bd8856a"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-f7th"
I20260812 06:16:44.225266 10489 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.226132 10689 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:16:44.226349 10489 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.226423 10489 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/master-0-root
uuid: "52e18c3f44ec447d95aa5ae99bd8856a"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-f7th"
I20260812 06:16:44.226486 10489 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-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:16:44.238281 10489 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:44.238638 10489 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:44.243178 10489 rpc_server.cc:307] RPC server started. Bound to: 127.10.62.126:35337
I20260812 06:16:44.243961 10741 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.62.126:35337 every 8 connection(s)
I20260812 06:16:44.250205 10742 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:16:44.255494 10742 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: Bootstrap starting.
I20260812 06:16:44.256546 10742 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:44.257547 10742 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: No bootstrap required, opened a new log
I20260812 06:16:44.257961 10742 raft_consensus.cc:359] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER }
I20260812 06:16:44.258055 10742 raft_consensus.cc:385] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:44.258076 10742 raft_consensus.cc:740] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 52e18c3f44ec447d95aa5ae99bd8856a, State: Initialized, Role: FOLLOWER
I20260812 06:16:44.258212 10742 consensus_queue.cc:260] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [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: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER }
I20260812 06:16:44.258281 10742 raft_consensus.cc:399] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:44.258306 10742 raft_consensus.cc:493] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:44.258390 10742 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:44.259125 10742 raft_consensus.cc:515] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER }
I20260812 06:16:44.259250 10742 leader_election.cc:304] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [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: 52e18c3f44ec447d95aa5ae99bd8856a; no voters: 
I20260812 06:16:44.259407 10742 leader_election.cc:290] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:44.259528 10745 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:44.259792 10745 raft_consensus.cc:697] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 1 LEADER]: Becoming Leader. State: Replica: 52e18c3f44ec447d95aa5ae99bd8856a, State: Running, Role: LEADER
I20260812 06:16:44.259846 10742 sys_catalog.cc:565] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:44.259985 10745 consensus_queue.cc:237] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [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: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER }
I20260812 06:16:44.260406 10746 sys_catalog.cc:455] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER } }
I20260812 06:16:44.260435 10747 sys_catalog.cc:455] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 52e18c3f44ec447d95aa5ae99bd8856a. Latest consensus state: current_term: 1 leader_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52e18c3f44ec447d95aa5ae99bd8856a" member_type: VOTER } }
I20260812 06:16:44.260493 10746 sys_catalog.cc:458] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:44.260519 10747 sys_catalog.cc:458] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:44.261767 10489 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:44.262197 10761 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:44.262255 10761 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:44.262342 10751 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:44.262903 10751 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:44.264678 10751 catalog_manager.cc:1383] Generated new cluster ID: 472f1388a27544a78f5bb68a41e678ad
I20260812 06:16:44.264737 10751 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:44.325031 10751 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:44.325578 10751 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:44.333849 10751 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: Generated new TSK 0
I20260812 06:16:44.334018 10751 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:44.390508 10489 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:44.392481 10764 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:16:44.392546 10763 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:16:44.392585 10766 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:16:44.392853 10489 server_base.cc:1061] running on GCE node
I20260812 06:16:44.393015 10489 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:44.393052 10489 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:16:44.393066 10489 hybrid_clock.cc:648] HybridClock initialized: now 1786515404393066 us; error 0 us; skew 500 ppm
I20260812 06:16:44.393877 10489 webserver.cc:533] Webserver started at http://127.10.62.65:35635/ using document root <none> and password file <none>
I20260812 06:16:44.394030 10489 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:44.394078 10489 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:44.394150 10489 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:44.394537 10489 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/instance:
uuid: "a30f81fc048a4b63a6845fbb42b145d3"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-f7th"
I20260812 06:16:44.395999 10489 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:44.396983 10771 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:16:44.397225 10489 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.397289 10489 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root
uuid: "a30f81fc048a4b63a6845fbb42b145d3"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-f7th"
I20260812 06:16:44.397357 10489 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-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:16:44.401948 10489 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:44.402271 10489 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:44.402549 10489 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:44.402952 10489 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:44.402995 10489 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:44.403034 10489 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:44.403062 10489 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:44.407811 10489 rpc_server.cc:307] RPC server started. Bound to: 127.10.62.65:46177
I20260812 06:16:44.407840 10834 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.62.65:46177 every 8 connection(s)
I20260812 06:16:44.415769 10835 heartbeater.cc:344] Connected to a master server at 127.10.62.126:35337
I20260812 06:16:44.415879 10835 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:44.416116 10835 heartbeater.cc:507] Master 127.10.62.126:35337 requested a full tablet report, sending...
I20260812 06:16:44.416757 10706 ts_manager.cc:194] Registered new tserver with Master: a30f81fc048a4b63a6845fbb42b145d3 (127.10.62.65:46177)
I20260812 06:16:44.417075 10489 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008848986s
I20260812 06:16:44.417562 10706 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34448
I20260812 06:16:44.424358 10706 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34464:
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:16:44.433262 10799 tablet_service.cc:1511] Processing CreateTablet for tablet e4f20b63c15c49c5b6c07fd2d5942f6e (DEFAULT_TABLE table=heavy-update-compaction-test [id=bc300c8227e0461e87b595fbd324ec4e]), partition=
I20260812 06:16:44.433557 10799 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e4f20b63c15c49c5b6c07fd2d5942f6e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:44.435685 10847 tablet_bootstrap.cc:492] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Bootstrap starting.
I20260812 06:16:44.436647 10847 tablet_bootstrap.cc:654] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:44.437875 10847 tablet_bootstrap.cc:492] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: No bootstrap required, opened a new log
I20260812 06:16:44.438022 10847 ts_tablet_manager.cc:1403] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:44.438504 10847 raft_consensus.cc:359] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a30f81fc048a4b63a6845fbb42b145d3" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 46177 } }
I20260812 06:16:44.438618 10847 raft_consensus.cc:385] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:44.438652 10847 raft_consensus.cc:740] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a30f81fc048a4b63a6845fbb42b145d3, State: Initialized, Role: FOLLOWER
I20260812 06:16:44.438784 10847 consensus_queue.cc:260] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [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: "a30f81fc048a4b63a6845fbb42b145d3" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 46177 } }
I20260812 06:16:44.438879 10847 raft_consensus.cc:399] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:44.438920 10847 raft_consensus.cc:493] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:44.438978 10847 raft_consensus.cc:3060] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:44.439944 10847 raft_consensus.cc:515] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a30f81fc048a4b63a6845fbb42b145d3" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 46177 } }
I20260812 06:16:44.440092 10847 leader_election.cc:304] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [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: a30f81fc048a4b63a6845fbb42b145d3; no voters: 
I20260812 06:16:44.440287 10847 leader_election.cc:290] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:44.440394 10849 raft_consensus.cc:2804] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:44.440591 10849 raft_consensus.cc:697] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 1 LEADER]: Becoming Leader. State: Replica: a30f81fc048a4b63a6845fbb42b145d3, State: Running, Role: LEADER
I20260812 06:16:44.440598 10847 ts_tablet_manager.cc:1434] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:16:44.440634 10835 heartbeater.cc:499] Master 127.10.62.126:35337 was elected leader, sending a full tablet report...
I20260812 06:16:44.440794 10849 consensus_queue.cc:237] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [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: "a30f81fc048a4b63a6845fbb42b145d3" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 46177 } }
I20260812 06:16:44.441926 10706 catalog_manager.cc:5719] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 reported cstate change: term changed from 0 to 1, leader changed from <none> to a30f81fc048a4b63a6845fbb42b145d3 (127.10.62.65). New cstate: current_term: 1 leader_uuid: "a30f81fc048a4b63a6845fbb42b145d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a30f81fc048a4b63a6845fbb42b145d3" member_type: VOTER last_known_addr { host: "127.10.62.65" port: 46177 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:44.500387 10489 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.013s	sys 0.008s
I20260812 06:16:44.658712 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushMRSOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=19.054940
I20260812 06:16:44.817225 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushMRSOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.158s	user 0.132s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":153,"dirs.run_wall_time_us":734,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38149,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:44.817989 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e): free 20290830 bytes of WAL
I20260812 06:16:44.818250 10776 log_reader.cc:385] T e4f20b63c15c49c5b6c07fd2d5942f6e: removed 2 log segments from log reader
I20260812 06:16:44.818315 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000001 (ops 1-6)
I20260812 06:16:44.818434 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000002 (ops 7-10)
I20260812 06:16:44.823688 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:44.824128 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:44.837837 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.014s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.838217 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling UndoDeltaBlockGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e): 16411393 bytes on disk
I20260812 06:16:44.838543 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: UndoDeltaBlockGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.838891 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:44.998411 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.159s	user 0.106s	sys 0.051s 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":404,"lbm_read_time_us":11370,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29899,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":288,"threads_started":5,"update_count":2000}
I20260812 06:16:44.999013 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:45.038938 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.040s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17588,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.039575 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:45.053682 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.054232 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:45.205687 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.151s	user 0.101s	sys 0.050s 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":657,"lbm_read_time_us":10247,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24753,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:16:45.206215 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:45.247071 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.041s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.247504 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:45.363751 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.116s	user 0.077s	sys 0.038s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":150,"lbm_read_time_us":5803,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21447,"lbm_writes_lt_1ms":343,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":276864,"update_count":1500}
I20260812 06:16:45.364387 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:45.426880 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.062s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":36378,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.427465 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:45.442808 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.443375 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:45.599646 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.156s	user 0.136s	sys 0.019s 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":637,"lbm_read_time_us":10765,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27369,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:16:45.600220 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:45.642957 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.043s	user 0.014s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18115,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.643420 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:45.652948 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.653319 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:45.812449 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.159s	user 0.102s	sys 0.055s 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":647,"lbm_read_time_us":11219,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24824,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:16:45.812995 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:45.855319 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.042s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14972,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.855973 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:45.872766 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.017s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.873325 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:46.060014 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.186s	user 0.091s	sys 0.075s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":8712,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27411,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:16:46.062489 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=14.095187
I20260812 06:16:46.137547 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.075s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.138046 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=4.173312
I20260812 06:16:46.230341 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.092s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5538513,"delete_count":0,"lbm_write_time_us":5126,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:16:46.230876 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=7.149875
I20260812 06:16:46.331395 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.100s	user 0.015s	sys 0.008s Metrics: {"bytes_written":9107615,"delete_count":0,"lbm_write_time_us":10577,"lbm_writes_lt_1ms":225,"reinsert_count":0,"update_count":1110}
I20260812 06:16:46.331943 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=8.142062
I20260812 06:16:46.428846 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.097s	user 0.025s	sys 0.000s Metrics: {"bytes_written":9969124,"delete_count":0,"lbm_write_time_us":10947,"lbm_writes_lt_1ms":246,"reinsert_count":0,"update_count":1215}
I20260812 06:16:46.429510 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=6.157687
I20260812 06:16:46.527263 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.097s	user 0.011s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9777,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.527935 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=7.149875
I20260812 06:16:46.630102 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.102s	user 0.021s	sys 0.004s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":11225,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:46.630769 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=7.149875
I20260812 06:16:46.727217 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.096s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8902491,"delete_count":0,"lbm_write_time_us":7750,"lbm_writes_lt_1ms":220,"reinsert_count":0,"update_count":1085}
I20260812 06:16:46.732364 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=9.134250
I20260812 06:16:46.831667 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.099s	user 0.027s	sys 0.008s Metrics: {"bytes_written":11199847,"delete_count":0,"lbm_write_time_us":15980,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":275,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1365}
I20260812 06:16:46.832362 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=3.181125
I20260812 06:16:46.934783 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.102s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5046218,"delete_count":0,"lbm_write_time_us":6716,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:16:46.935454 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=9.134250
I20260812 06:16:47.041080 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.105s	user 0.024s	sys 0.007s Metrics: {"bytes_written":11363934,"delete_count":0,"lbm_write_time_us":13053,"lbm_writes_lt_1ms":280,"reinsert_count":0,"update_count":1385}
I20260812 06:16:47.041776 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=7.149875
I20260812 06:16:47.144017 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.102s	user 0.011s	sys 0.018s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11625,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:47.144819 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=8.142062
I20260812 06:16:47.245568 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.101s	user 0.009s	sys 0.020s Metrics: {"bytes_written":9599897,"delete_count":0,"lbm_write_time_us":10527,"lbm_writes_lt_1ms":237,"reinsert_count":0,"update_count":1170}
I20260812 06:16:47.247144 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=9.134250
I20260812 06:16:47.344954 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.098s	user 0.015s	sys 0.012s Metrics: {"bytes_written":10502428,"delete_count":0,"lbm_write_time_us":10810,"lbm_writes_lt_1ms":259,"reinsert_count":0,"update_count":1280}
I20260812 06:16:47.345654 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=6.157687
I20260812 06:16:47.449139 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.103s	user 0.010s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7497,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.449712 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=6.157687
I20260812 06:16:47.551254 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.101s	user 0.009s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10901,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.552232 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=7.149875
I20260812 06:16:47.645629 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.093s	user 0.022s	sys 0.004s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":11342,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:47.646229 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=6.157687
I20260812 06:16:47.745657 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.099s	user 0.006s	sys 0.018s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9677,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.746752 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=9.134250
I20260812 06:16:47.848003 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.101s	user 0.023s	sys 0.012s Metrics: {"bytes_written":10584478,"delete_count":0,"lbm_write_time_us":14818,"lbm_writes_lt_1ms":261,"reinsert_count":0,"update_count":1290}
I20260812 06:16:47.848803 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=4.173312
I20260812 06:16:47.945711 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.097s	user 0.013s	sys 0.006s Metrics: {"bytes_written":6400028,"delete_count":0,"lbm_write_time_us":8200,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:16:47.946305 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=9.134250
I20260812 06:16:47.994871 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.048s	user 0.022s	sys 0.011s Metrics: {"bytes_written":11322919,"delete_count":0,"lbm_write_time_us":15321,"lbm_writes_lt_1ms":279,"reinsert_count":0,"update_count":1380}
I20260812 06:16:47.995451 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:48.023247 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.028s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.023810 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushMRSOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.195565
I20260812 06:16:48.062716 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushMRSOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.039s	user 0.031s	sys 0.005s Metrics: {"bytes_written":2873823,"cfile_init":1,"dirs.queue_time_us":267,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":3871,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3249,"lbm_writes_lt_1ms":49,"peak_mem_usage":0,"rows_written":70,"spinlock_wait_cycles":768,"thread_start_us":129,"threads_started":1}
I20260812 06:16:48.063524 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e): free 279425944 bytes of WAL
I20260812 06:16:48.063874 10776 log_reader.cc:385] T e4f20b63c15c49c5b6c07fd2d5942f6e: removed 27 log segments from log reader
I20260812 06:16:48.063956 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000003 (ops 11-15)
I20260812 06:16:48.064016 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000004 (ops 16-20)
I20260812 06:16:48.064060 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000005 (ops 21-25)
I20260812 06:16:48.064102 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000006 (ops 26-30)
I20260812 06:16:48.064149 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000007 (ops 31-35)
I20260812 06:16:48.064193 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000008 (ops 36-41)
I20260812 06:16:48.064235 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000009 (ops 42-46)
I20260812 06:16:48.064281 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000010 (ops 47-51)
I20260812 06:16:48.064328 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000011 (ops 52-56)
I20260812 06:16:48.064373 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000012 (ops 57-61)
I20260812 06:16:48.064416 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000013 (ops 62-66)
I20260812 06:16:48.064479 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000014 (ops 67-71)
I20260812 06:16:48.064524 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000015 (ops 72-76)
I20260812 06:16:48.064569 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000016 (ops 77-81)
I20260812 06:16:48.064613 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000017 (ops 82-86)
I20260812 06:16:48.064675 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000018 (ops 87-91)
I20260812 06:16:48.064720 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000019 (ops 92-96)
I20260812 06:16:48.064759 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000020 (ops 97-101)
I20260812 06:16:48.064795 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000021 (ops 102-106)
I20260812 06:16:48.064832 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000022 (ops 107-111)
I20260812 06:16:48.064874 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000023 (ops 112-116)
I20260812 06:16:48.064917 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000024 (ops 117-121)
I20260812 06:16:48.064962 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000025 (ops 122-126)
I20260812 06:16:48.065009 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000026 (ops 127-131)
I20260812 06:16:48.065053 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000027 (ops 132-136)
I20260812 06:16:48.065097 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000028 (ops 137-141)
I20260812 06:16:48.065145 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000029 (ops 142-146)
I20260812 06:16:48.107316 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.044s	user 0.000s	sys 0.040s Metrics: {}
I20260812 06:16:48.107803 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling UndoDeltaBlockGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e): 924 bytes on disk
I20260812 06:16:48.108309 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: UndoDeltaBlockGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.108834 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=6.157687
I20260812 06:16:48.137607 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.029s	user 0.014s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8788,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.138098 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e): free 12017949 bytes of WAL
I20260812 06:16:48.138279 10776 log_reader.cc:385] T e4f20b63c15c49c5b6c07fd2d5942f6e: removed 1 log segments from log reader
I20260812 06:16:48.138319 10776 log.cc:1079] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: Deleting log segment in path: /tmp/dist-test-taskauIzup/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515398772005-10489-0/minicluster-data/ts-0-root/wals/e4f20b63c15c49c5b6c07fd2d5942f6e/wal-000000030 (ops 147-151)
I20260812 06:16:48.140054 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: LogGCOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:48.140316 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=2.188937
I20260812 06:16:48.149914 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.150285 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=1.000000
I20260812 06:16:49.513073 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: MajorDeltaCompactionOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 1.363s	user 0.875s	sys 0.481s Metrics: {"cfile_cache_miss":4953,"cfile_cache_miss_bytes":205283397,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":23,"delta_iterators_relevant":23,"dirs.queue_time_us":304,"lbm_read_time_us":85052,"lbm_reads_lt_1ms":4993,"lbm_write_time_us":269015,"lbm_writes_lt_1ms":4947,"peak_mem_usage":609885068,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":354,"threads_started":7,"update_count":24500}
I20260812 06:16:49.513568 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=81.563937
I20260812 06:16:49.731053 10489 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.231s	user 1.751s	sys 0.187s
I20260812 06:16:49.781390 10489 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.050s	user 0.001s	sys 0.000s
I20260812 06:16:49.781940 10489 tablet_server.cc:179] TabletServer@127.10.62.65:0 shutting down...
I20260812 06:16:49.785390 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.272s	user 0.133s	sys 0.071s Metrics: {"bytes_written":86151030,"delete_count":0,"lbm_write_time_us":138756,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":2104,"reinsert_count":0,"update_count":10500}
I20260812 06:16:49.785916 10836 maintenance_manager.cc:419] P a30f81fc048a4b63a6845fbb42b145d3: Scheduling FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e): perf score=10.126437
I20260812 06:16:50.194566 10776 maintenance_manager.cc:643] P a30f81fc048a4b63a6845fbb42b145d3: FlushDeltaMemStoresOp(e4f20b63c15c49c5b6c07fd2d5942f6e) complete. Timing: real 0.408s	user 0.011s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":196344,"lbm_writes_1-10_ms":1,"lbm_writes_gt_100_ms":1,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.195240 10489 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:50.195490 10489 tablet_replica.cc:333] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3: stopping tablet replica
I20260812 06:16:50.195641 10489 raft_consensus.cc:2243] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:50.195823 10489 raft_consensus.cc:2272] T e4f20b63c15c49c5b6c07fd2d5942f6e P a30f81fc048a4b63a6845fbb42b145d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:50.209257 10489 tablet_server.cc:196] TabletServer@127.10.62.65:0 shutdown complete.
I20260812 06:16:50.274953 10489 master.cc:562] Master@127.10.62.126:35337 shutting down...
I20260812 06:16:50.278183 10489 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:50.278362 10489 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:50.278435 10489 tablet_replica.cc:333] T 00000000000000000000000000000000 P 52e18c3f44ec447d95aa5ae99bd8856a: stopping tablet replica
I20260812 06:16:50.290712 10489 master.cc:584] Master@127.10.62.126:35337 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6177 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11615 ms total)

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