[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:09.715231 17617 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.52.126:43953
I20260812 06:19:09.716334 17617 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:09.716981 17617 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.725951 17625 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.726044 17624 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.726146 17617 server_base.cc:1061] running on GCE node
W20260812 06:19:09.726292 17627 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.726946 17617 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.727051 17617 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:09.727080 17617 hybrid_clock.cc:648] HybridClock initialized: now 1786515549727078 us; error 0 us; skew 500 ppm
I20260812 06:19:09.729252 17617 webserver.cc:533] Webserver started at http://127.17.52.126:37025/ using document root <none> and password file <none>
I20260812 06:19:09.729826 17617 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.729905 17617 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.730116 17617 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.732095 17617 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/master-0-root/instance:
uuid: "2c7a5b6b715149cd8b26c7bffc821f6d"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-dhph"
I20260812 06:19:09.736065 17617 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:19:09.738683 17632 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.740249 17617 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:09.740434 17617 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/master-0-root
uuid: "2c7a5b6b715149cd8b26c7bffc821f6d"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-dhph"
I20260812 06:19:09.740576 17617 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:09.765249 17617 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.766053 17617 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:09.766270 17617 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.774663 17696 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.52.126:43953 every 8 connection(s)
I20260812 06:19:09.774721 17617 rpc_server.cc:307] RPC server started. Bound to: 127.17.52.126:43953
I20260812 06:19:09.777359 17697 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:09.783046 17697 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: Bootstrap starting.
I20260812 06:19:09.785442 17697 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.786412 17697 log.cc:826] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:09.788487 17697 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: No bootstrap required, opened a new log
I20260812 06:19:09.791584 17697 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER }
I20260812 06:19:09.791834 17697 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.791937 17697 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2c7a5b6b715149cd8b26c7bffc821f6d, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.792614 17697 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [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: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER }
I20260812 06:19:09.792819 17697 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.792933 17697 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.793090 17697 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.794018 17697 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER }
I20260812 06:19:09.794518 17697 leader_election.cc:304] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [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: 2c7a5b6b715149cd8b26c7bffc821f6d; no voters: 
I20260812 06:19:09.794984 17697 leader_election.cc:290] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.795188 17701 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.795523 17701 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 1 LEADER]: Becoming Leader. State: Replica: 2c7a5b6b715149cd8b26c7bffc821f6d, State: Running, Role: LEADER
I20260812 06:19:09.796005 17701 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [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: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER }
I20260812 06:19:09.796106 17697 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:09.798290 17702 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER } }
I20260812 06:19:09.798417 17702 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:09.798493 17617 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:09.798609 17703 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2c7a5b6b715149cd8b26c7bffc821f6d. Latest consensus state: current_term: 1 leader_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c7a5b6b715149cd8b26c7bffc821f6d" member_type: VOTER } }
I20260812 06:19:09.798695 17703 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:09.800930 17716 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:09.801014 17716 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:09.801115 17717 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:09.801883 17717 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:09.806968 17717 catalog_manager.cc:1383] Generated new cluster ID: f88458e1dd7f49f2adaa85c2d6a45dc1
I20260812 06:19:09.807071 17717 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:09.813712 17717 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:09.814883 17717 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:09.825352 17717 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: Generated new TSK 0
I20260812 06:19:09.826161 17717 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:09.831485 17617 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.834475 17721 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.834511 17722 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.834898 17725 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.834964 17617 server_base.cc:1061] running on GCE node
I20260812 06:19:09.835206 17617 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.835264 17617 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:09.835284 17617 hybrid_clock.cc:648] HybridClock initialized: now 1786515549835284 us; error 0 us; skew 500 ppm
I20260812 06:19:09.836325 17617 webserver.cc:533] Webserver started at http://127.17.52.65:34901/ using document root <none> and password file <none>
I20260812 06:19:09.836532 17617 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.836588 17617 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.836702 17617 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.837152 17617 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/instance:
uuid: "2d4cdac2eef645fcade29571a596cdb7"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-dhph"
I20260812 06:19:09.839080 17617 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:19:09.840457 17730 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.840780 17617 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:09.840951 17617 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root
uuid: "2d4cdac2eef645fcade29571a596cdb7"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-dhph"
I20260812 06:19:09.841071 17617 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:09.858760 17617 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.859339 17617 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.859956 17617 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:09.860924 17617 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:09.860981 17617 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.861055 17617 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:09.861100 17617 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.869021 17617 rpc_server.cc:307] RPC server started. Bound to: 127.17.52.65:43695
I20260812 06:19:09.869055 17804 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.52.65:43695 every 8 connection(s)
I20260812 06:19:09.884814 17805 heartbeater.cc:344] Connected to a master server at 127.17.52.126:43953
I20260812 06:19:09.885180 17805 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:09.885684 17805 heartbeater.cc:507] Master 127.17.52.126:43953 requested a full tablet report, sending...
I20260812 06:19:09.887526 17652 ts_manager.cc:194] Registered new tserver with Master: 2d4cdac2eef645fcade29571a596cdb7 (127.17.52.65:43695)
I20260812 06:19:09.888200 17617 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018256921s
I20260812 06:19:09.889113 17652 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33910
I20260812 06:19:09.898885 17652 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33920:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:09.914723 17763 tablet_service.cc:1511] Processing CreateTablet for tablet a2061af8070f4ff986eaf5693b87f682 (DEFAULT_TABLE table=heavy-update-compaction-test [id=439872314d58487cbff94b8932e1f497]), partition=
I20260812 06:19:09.915290 17763 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a2061af8070f4ff986eaf5693b87f682. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:09.918197 17817 tablet_bootstrap.cc:492] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Bootstrap starting.
I20260812 06:19:09.919582 17817 tablet_bootstrap.cc:654] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.921200 17817 tablet_bootstrap.cc:492] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: No bootstrap required, opened a new log
I20260812 06:19:09.921346 17817 ts_tablet_manager.cc:1403] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:09.922240 17817 raft_consensus.cc:359] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d4cdac2eef645fcade29571a596cdb7" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 43695 } }
I20260812 06:19:09.922387 17817 raft_consensus.cc:385] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.922427 17817 raft_consensus.cc:740] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d4cdac2eef645fcade29571a596cdb7, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.922665 17817 consensus_queue.cc:260] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [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: "2d4cdac2eef645fcade29571a596cdb7" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 43695 } }
I20260812 06:19:09.922783 17817 raft_consensus.cc:399] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.922874 17817 raft_consensus.cc:493] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.923017 17817 raft_consensus.cc:3060] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.924191 17817 raft_consensus.cc:515] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d4cdac2eef645fcade29571a596cdb7" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 43695 } }
I20260812 06:19:09.924364 17817 leader_election.cc:304] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [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: 2d4cdac2eef645fcade29571a596cdb7; no voters: 
I20260812 06:19:09.924595 17817 leader_election.cc:290] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.924795 17819 raft_consensus.cc:2804] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.924942 17817 ts_tablet_manager.cc:1434] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Time spent starting tablet: real 0.004s	user 0.001s	sys 0.003s
I20260812 06:19:09.925065 17819 raft_consensus.cc:697] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 1 LEADER]: Becoming Leader. State: Replica: 2d4cdac2eef645fcade29571a596cdb7, State: Running, Role: LEADER
I20260812 06:19:09.925201 17805 heartbeater.cc:499] Master 127.17.52.126:43953 was elected leader, sending a full tablet report...
I20260812 06:19:09.925323 17819 consensus_queue.cc:237] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [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: "2d4cdac2eef645fcade29571a596cdb7" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 43695 } }
I20260812 06:19:09.928574 17651 catalog_manager.cc:5719] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2d4cdac2eef645fcade29571a596cdb7 (127.17.52.65). New cstate: current_term: 1 leader_uuid: "2d4cdac2eef645fcade29571a596cdb7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d4cdac2eef645fcade29571a596cdb7" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 43695 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:10.006659 17617 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.070s	user 0.021s	sys 0.019s
I20260812 06:19:10.120399 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushMRSOp(a2061af8070f4ff986eaf5693b87f682): perf score=15.086190
I20260812 06:19:10.300189 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushMRSOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.179s	user 0.129s	sys 0.047s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1134,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44427,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":129,"threads_started":1,"update_count":1500}
I20260812 06:19:10.301445 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling LogGCOp(a2061af8070f4ff986eaf5693b87f682): free 8725963 bytes of WAL
I20260812 06:19:10.301802 17736 log_reader.cc:385] T a2061af8070f4ff986eaf5693b87f682: removed 1 log segments from log reader
I20260812 06:19:10.301873 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000001 (ops 1-6)
I20260812 06:19:10.304345 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: LogGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:10.304746 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682): 12308962 bytes on disk
I20260812 06:19:10.305421 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:10.305860 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:10.323383 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.323866 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:10.483028 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.159s	user 0.133s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":8765,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28101,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":356,"threads_started":5,"update_count":2000}
I20260812 06:19:10.483683 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:10.536382 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.052s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18100,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.536902 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:10.551671 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.552454 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:10.713392 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.161s	user 0.142s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":8287,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32871,"lbm_writes_lt_1ms":443,"mutex_wait_us":145,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:19:10.713943 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:10.777211 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.063s	user 0.015s	sys 0.030s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15982,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.778012 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:10.790257 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.790829 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:10.966300 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.175s	user 0.116s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":12877,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28223,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:19:10.967079 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:11.025053 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.058s	user 0.021s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":24471,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.025765 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:11.037999 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.038769 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:11.184715 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.146s	user 0.133s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":10673,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25806,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:11.185784 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:11.240823 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.055s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19643,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.241338 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:11.254351 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.255185 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:11.399448 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.144s	user 0.118s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1930,"lbm_read_time_us":10060,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28844,"lbm_writes_lt_1ms":443,"mutex_wait_us":446,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:11.399996 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:11.438669 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.038s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16488,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.439312 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:11.545918 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.106s	user 0.080s	sys 0.026s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":667,"lbm_read_time_us":6110,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20028,"lbm_writes_lt_1ms":343,"mutex_wait_us":323,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":1500}
I20260812 06:19:11.546525 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:11.590365 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.044s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18874,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.590940 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:11.601812 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.602315 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:11.743228 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.141s	user 0.113s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":10267,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27946,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:11.743947 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:11.791936 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.048s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:11.792550 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:11.805583 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.806162 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushMRSOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:11.837949 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushMRSOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1652,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1642,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:11.838871 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling LogGCOp(a2061af8070f4ff986eaf5693b87f682): free 133024354 bytes of WAL
I20260812 06:19:11.839237 17736 log_reader.cc:385] T a2061af8070f4ff986eaf5693b87f682: removed 13 log segments from log reader
I20260812 06:19:11.839347 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000002 (ops 7-11)
I20260812 06:19:11.839416 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000003 (ops 12-16)
I20260812 06:19:11.839484 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000004 (ops 17-21)
I20260812 06:19:11.839533 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000005 (ops 22-26)
I20260812 06:19:11.839574 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000006 (ops 27-30)
I20260812 06:19:11.839619 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000007 (ops 31-35)
I20260812 06:19:11.839660 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000008 (ops 36-40)
I20260812 06:19:11.839813 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000009 (ops 41-45)
I20260812 06:19:11.839871 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000010 (ops 46-50)
I20260812 06:19:11.839921 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000011 (ops 51-55)
I20260812 06:19:11.839962 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000012 (ops 56-60)
I20260812 06:19:11.840005 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000013 (ops 61-65)
I20260812 06:19:11.840047 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000014 (ops 66-70)
I20260812 06:19:11.870015 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: LogGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:11.870688 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682): 480 bytes on disk
I20260812 06:19:11.871272 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.871940 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=3.181125
I20260812 06:19:11.890924 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":5251341,"delete_count":0,"lbm_write_time_us":7716,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:19:11.891489 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.196750
I20260812 06:19:11.904626 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":4698,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:19:11.905308 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:12.115875 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.210s	user 0.154s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1073,"lbm_read_time_us":14814,"lbm_reads_lt_1ms":674,"lbm_write_time_us":43137,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14080,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:19:12.116689 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=14.095187
I20260812 06:19:12.182066 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.065s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26497,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.182792 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:12.199002 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.199543 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:12.365581 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.166s	user 0.119s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":12139,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32864,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:12.366451 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=11.118625
I20260812 06:19:12.418011 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.051s	user 0.019s	sys 0.029s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":22197,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.418603 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:12.442160 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.023s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:19:12.442736 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:12.455734 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4768,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:12.456360 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:12.613114 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.157s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733840,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":940,"lbm_read_time_us":11396,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31055,"lbm_writes_lt_1ms":543,"mutex_wait_us":163,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:12.614205 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:12.664258 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.050s	user 0.037s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18795,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.664888 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:12.676853 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.677526 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:12.812350 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.134s	user 0.106s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":796,"lbm_read_time_us":9713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27045,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.813105 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:12.872977 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.060s	user 0.029s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19056,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.873628 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:12.892567 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.893236 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:13.054986 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.161s	user 0.122s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":11690,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27029,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:13.055656 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:13.108659 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.053s	user 0.024s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20965,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.109223 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:13.122059 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.122637 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:13.266824 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.144s	user 0.101s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1547,"lbm_read_time_us":10597,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28342,"lbm_writes_lt_1ms":443,"mutex_wait_us":217,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:19:13.268100 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:13.316490 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.048s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17546,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.317006 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:13.328670 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.329623 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushMRSOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:13.364622 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushMRSOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.035s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1764,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2056,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:13.365372 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling LogGCOp(a2061af8070f4ff986eaf5693b87f682): free 120100284 bytes of WAL
I20260812 06:19:13.365612 17736 log_reader.cc:385] T a2061af8070f4ff986eaf5693b87f682: removed 12 log segments from log reader
I20260812 06:19:13.365674 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000015 (ops 71-74)
I20260812 06:19:13.365731 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000016 (ops 75-79)
I20260812 06:19:13.365796 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000017 (ops 80-84)
I20260812 06:19:13.365839 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000018 (ops 85-89)
I20260812 06:19:13.365876 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000019 (ops 90-94)
I20260812 06:19:13.365927 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000020 (ops 95-98)
I20260812 06:19:13.365967 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000021 (ops 99-103)
I20260812 06:19:13.366005 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000022 (ops 104-108)
I20260812 06:19:13.366043 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000023 (ops 109-113)
I20260812 06:19:13.366083 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000024 (ops 114-118)
I20260812 06:19:13.366122 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000025 (ops 119-122)
I20260812 06:19:13.366160 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000026 (ops 123-127)
I20260812 06:19:13.392550 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: LogGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:13.393033 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682): 448 bytes on disk
I20260812 06:19:13.393601 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682) 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:19:13.394199 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=3.181125
I20260812 06:19:13.414098 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7208,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:13.414556 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:13.430526 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6028,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.431236 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:13.615221 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.184s	user 0.138s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1212,"lbm_read_time_us":13074,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35372,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"thread_start_us":790,"threads_started":1,"update_count":3000}
I20260812 06:19:13.616967 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=14.095187
I20260812 06:19:13.669991 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.053s	user 0.020s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23212,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.670522 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:13.684166 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.684690 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:13.844599 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.160s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":490,"lbm_read_time_us":10625,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32256,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:13.845430 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=11.118625
I20260812 06:19:13.880447 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.035s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14769,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.881155 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:13.899350 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5001,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.900156 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.037032 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.137s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631302,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1107,"lbm_read_time_us":7329,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27670,"lbm_writes_lt_1ms":443,"mutex_wait_us":296,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":31616,"update_count":2000}
I20260812 06:19:14.037710 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:14.088063 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.050s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17800,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.088891 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:14.105140 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.105719 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.239925 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.134s	user 0.110s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1418,"lbm_read_time_us":9048,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27086,"lbm_writes_lt_1ms":443,"mutex_wait_us":427,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2000}
I20260812 06:19:14.240715 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:14.303171 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.062s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17295,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.303812 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:14.316015 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.316500 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.468516 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.152s	user 0.089s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24014,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2000}
I20260812 06:19:14.469137 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:14.519691 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.050s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15590,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.520263 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:14.531284 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.531813 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.684499 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.152s	user 0.112s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":11558,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29168,"lbm_writes_lt_1ms":443,"mutex_wait_us":121,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:14.685132 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:14.723032 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.038s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.723963 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.843427 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.119s	user 0.079s	sys 0.040s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":701,"lbm_read_time_us":7564,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23221,"lbm_writes_lt_1ms":343,"mutex_wait_us":53,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":1500}
I20260812 06:19:14.844154 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=10.126437
I20260812 06:19:14.895022 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.051s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19167,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.895567 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:14.908684 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.909230 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushMRSOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:14.947798 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushMRSOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.038s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1652,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2693,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:14.948597 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling LogGCOp(a2061af8070f4ff986eaf5693b87f682): free 124257554 bytes of WAL
I20260812 06:19:14.948843 17736 log_reader.cc:385] T a2061af8070f4ff986eaf5693b87f682: removed 12 log segments from log reader
I20260812 06:19:14.948911 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000027 (ops 128-132)
I20260812 06:19:14.948971 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000028 (ops 133-137)
I20260812 06:19:14.949011 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000029 (ops 138-142)
I20260812 06:19:14.949055 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000030 (ops 143-147)
I20260812 06:19:14.949096 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000031 (ops 148-152)
I20260812 06:19:14.949138 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000032 (ops 153-157)
I20260812 06:19:14.949180 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000033 (ops 158-162)
I20260812 06:19:14.949222 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000034 (ops 163-167)
I20260812 06:19:14.949263 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000035 (ops 168-172)
I20260812 06:19:14.949306 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000036 (ops 173-176)
I20260812 06:19:14.949347 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000037 (ops 177-181)
I20260812 06:19:14.949388 17736 log.cc:1079] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/a2061af8070f4ff986eaf5693b87f682/wal-000000038 (ops 182-186)
I20260812 06:19:14.978873 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: LogGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:14.979440 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682): 472 bytes on disk
I20260812 06:19:14.980000 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: UndoDeltaBlockGCOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.980938 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=3.181125
I20260812 06:19:14.998845 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5635,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:14.999611 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:15.011997 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.012929 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:15.229566 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.216s	user 0.120s	sys 0.096s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":888,"lbm_read_time_us":15575,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38949,"lbm_writes_lt_1ms":643,"mutex_wait_us":382,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:19:15.230855 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=14.095187
I20260812 06:19:15.296656 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.065s	user 0.041s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26494,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.297389 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682): perf score=2.188937
I20260812 06:19:15.309352 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: FlushDeltaMemStoresOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.310103 17806 maintenance_manager.cc:419] P 2d4cdac2eef645fcade29571a596cdb7: Scheduling MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682): perf score=1.000000
I20260812 06:19:15.355331 17617 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.349s	user 2.031s	sys 0.101s
I20260812 06:19:15.430399 17617 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:19:15.431187 17617 tablet_server.cc:179] TabletServer@127.17.52.65:0 shutting down...
I20260812 06:19:15.476047 17736 maintenance_manager.cc:643] P 2d4cdac2eef645fcade29571a596cdb7: MajorDeltaCompactionOp(a2061af8070f4ff986eaf5693b87f682) complete. Timing: real 0.166s	user 0.118s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":14668,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27077,"lbm_writes_lt_1ms":543,"mutex_wait_us":108,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:15.476955 17617 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:15.477463 17617 tablet_replica.cc:333] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7: stopping tablet replica
I20260812 06:19:15.477782 17617 raft_consensus.cc:2243] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:15.478060 17617 raft_consensus.cc:2272] T a2061af8070f4ff986eaf5693b87f682 P 2d4cdac2eef645fcade29571a596cdb7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:15.496258 17617 tablet_server.cc:196] TabletServer@127.17.52.65:0 shutdown complete.
I20260812 06:19:15.525279 17617 master.cc:562] Master@127.17.52.126:43953 shutting down...
I20260812 06:19:15.530244 17617 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:15.530499 17617 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:15.530643 17617 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2c7a5b6b715149cd8b26c7bffc821f6d: stopping tablet replica
I20260812 06:19:15.543836 17617 master.cc:584] Master@127.17.52.126:43953 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5918 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:15.644888 17617 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.52.126:33127
I20260812 06:19:15.645336 17617 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:15.648523 17839 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.648654 17617 server_base.cc:1061] running on GCE node
W20260812 06:19:15.648746 17842 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:15.648747 17840 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.649127 17617 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:15.649192 17617 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:15.649214 17617 hybrid_clock.cc:648] HybridClock initialized: now 1786515555649213 us; error 0 us; skew 500 ppm
I20260812 06:19:15.650404 17617 webserver.cc:533] Webserver started at http://127.17.52.126:40839/ using document root <none> and password file <none>
I20260812 06:19:15.650552 17617 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:15.650658 17617 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:15.650730 17617 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:15.651115 17617 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/master-0-root/instance:
uuid: "1a2d14b1f88c48519596bf200fc56dd3"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-dhph"
I20260812 06:19:15.652678 17617 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:15.653834 17848 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:15.654311 17617 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:15.654417 17617 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/master-0-root
uuid: "1a2d14b1f88c48519596bf200fc56dd3"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-dhph"
I20260812 06:19:15.654512 17617 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:15.667393 17617 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:15.667878 17617 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:15.672940 17617 rpc_server.cc:307] RPC server started. Bound to: 127.17.52.126:33127
I20260812 06:19:15.676394 17909 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.52.126:33127 every 8 connection(s)
I20260812 06:19:15.679052 17910 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:15.681318 17910 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3: Bootstrap starting.
I20260812 06:19:15.682296 17910 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:15.683687 17910 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3: No bootstrap required, opened a new log
I20260812 06:19:15.684218 17910 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER }
I20260812 06:19:15.684319 17910 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:15.684342 17910 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1a2d14b1f88c48519596bf200fc56dd3, State: Initialized, Role: FOLLOWER
I20260812 06:19:15.684526 17910 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [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: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER }
I20260812 06:19:15.684620 17910 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:15.684684 17910 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:15.684746 17910 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:15.685601 17910 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER }
I20260812 06:19:15.685756 17910 leader_election.cc:304] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [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: 1a2d14b1f88c48519596bf200fc56dd3; no voters: 
I20260812 06:19:15.686019 17910 leader_election.cc:290] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:15.686234 17913 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:15.686470 17913 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 1 LEADER]: Becoming Leader. State: Replica: 1a2d14b1f88c48519596bf200fc56dd3, State: Running, Role: LEADER
I20260812 06:19:15.686614 17910 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:15.686753 17913 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [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: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER }
I20260812 06:19:15.687343 17915 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1a2d14b1f88c48519596bf200fc56dd3. Latest consensus state: current_term: 1 leader_uuid: "1a2d14b1f88c48519596bf200fc56dd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER } }
I20260812 06:19:15.687493 17915 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:15.687666 17914 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1a2d14b1f88c48519596bf200fc56dd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a2d14b1f88c48519596bf200fc56dd3" member_type: VOTER } }
I20260812 06:19:15.687810 17914 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:15.688066 17923 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:15.688982 17923 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:15.689159 17617 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:15.691107 17923 catalog_manager.cc:1383] Generated new cluster ID: bedfabb757f9499694a4eb95e545538c
I20260812 06:19:15.691174 17923 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:15.701447 17923 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:15.702117 17923 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:15.713121 17923 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3: Generated new TSK 0
I20260812 06:19:15.713441 17923 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:15.721869 17617 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:15.724647 17937 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.724948 17617 server_base.cc:1061] running on GCE node
W20260812 06:19:15.724903 17933 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:15.724864 17934 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.725414 17617 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:15.725482 17617 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:15.725502 17617 hybrid_clock.cc:648] HybridClock initialized: now 1786515555725502 us; error 0 us; skew 500 ppm
I20260812 06:19:15.726698 17617 webserver.cc:533] Webserver started at http://127.17.52.65:34363/ using document root <none> and password file <none>
I20260812 06:19:15.726909 17617 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:15.726979 17617 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:15.727066 17617 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:15.727748 17617 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/instance:
uuid: "472e2ae756d34370b671a2b3b3db6b2a"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-dhph"
I20260812 06:19:15.729591 17617 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:15.731041 17944 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:15.731400 17617 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:15.731499 17617 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root
uuid: "472e2ae756d34370b671a2b3b3db6b2a"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-dhph"
I20260812 06:19:15.731592 17617 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:15.759012 17617 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:15.759509 17617 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:15.759845 17617 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:15.760629 17617 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:15.760681 17617 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:15.760756 17617 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:15.760905 17617 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:15.766952 17617 rpc_server.cc:307] RPC server started. Bound to: 127.17.52.65:38041
I20260812 06:19:15.767234 18015 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.52.65:38041 every 8 connection(s)
I20260812 06:19:15.779397 18016 heartbeater.cc:344] Connected to a master server at 127.17.52.126:33127
I20260812 06:19:15.779560 18016 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:15.779815 18016 heartbeater.cc:507] Master 127.17.52.126:33127 requested a full tablet report, sending...
I20260812 06:19:15.780640 17870 ts_manager.cc:194] Registered new tserver with Master: 472e2ae756d34370b671a2b3b3db6b2a (127.17.52.65:38041)
I20260812 06:19:15.781445 17617 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013792391s
I20260812 06:19:15.781517 17870 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54290
I20260812 06:19:15.790773 17870 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54306:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:15.801657 17975 tablet_service.cc:1511] Processing CreateTablet for tablet d7f77ff339584fa086a54df49bce0010 (DEFAULT_TABLE table=heavy-update-compaction-test [id=771fdec353b34544ad5e30570c43d1de]), partition=
I20260812 06:19:15.801975 17975 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d7f77ff339584fa086a54df49bce0010. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:15.804419 18030 tablet_bootstrap.cc:492] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Bootstrap starting.
I20260812 06:19:15.805488 18030 tablet_bootstrap.cc:654] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:15.807081 18030 tablet_bootstrap.cc:492] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: No bootstrap required, opened a new log
I20260812 06:19:15.807191 18030 ts_tablet_manager.cc:1403] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:15.807724 18030 raft_consensus.cc:359] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "472e2ae756d34370b671a2b3b3db6b2a" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 38041 } }
I20260812 06:19:15.807828 18030 raft_consensus.cc:385] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:15.807853 18030 raft_consensus.cc:740] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 472e2ae756d34370b671a2b3b3db6b2a, State: Initialized, Role: FOLLOWER
I20260812 06:19:15.807984 18030 consensus_queue.cc:260] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [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: "472e2ae756d34370b671a2b3b3db6b2a" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 38041 } }
I20260812 06:19:15.808072 18030 raft_consensus.cc:399] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:15.808097 18030 raft_consensus.cc:493] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:15.808130 18030 raft_consensus.cc:3060] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:15.808907 18030 raft_consensus.cc:515] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "472e2ae756d34370b671a2b3b3db6b2a" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 38041 } }
I20260812 06:19:15.809037 18030 leader_election.cc:304] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [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: 472e2ae756d34370b671a2b3b3db6b2a; no voters: 
I20260812 06:19:15.809212 18030 leader_election.cc:290] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:15.809417 18032 raft_consensus.cc:2804] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:15.809522 18030 ts_tablet_manager.cc:1434] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:15.809577 18016 heartbeater.cc:499] Master 127.17.52.126:33127 was elected leader, sending a full tablet report...
I20260812 06:19:15.809600 18032 raft_consensus.cc:697] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 1 LEADER]: Becoming Leader. State: Replica: 472e2ae756d34370b671a2b3b3db6b2a, State: Running, Role: LEADER
I20260812 06:19:15.809769 18032 consensus_queue.cc:237] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [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: "472e2ae756d34370b671a2b3b3db6b2a" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 38041 } }
I20260812 06:19:15.811514 17870 catalog_manager.cc:5719] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a reported cstate change: term changed from 0 to 1, leader changed from <none> to 472e2ae756d34370b671a2b3b3db6b2a (127.17.52.65). New cstate: current_term: 1 leader_uuid: "472e2ae756d34370b671a2b3b3db6b2a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "472e2ae756d34370b671a2b3b3db6b2a" member_type: VOTER last_known_addr { host: "127.17.52.65" port: 38041 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:15.877678 17617 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.018s	sys 0.007s
I20260812 06:19:16.018177 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushMRSOp(d7f77ff339584fa086a54df49bce0010): perf score=15.086190
I20260812 06:19:16.175886 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushMRSOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.157s	user 0.116s	sys 0.040s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1013,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40800,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:16.176613 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling LogGCOp(d7f77ff339584fa086a54df49bce0010): free 20743880 bytes of WAL
I20260812 06:19:16.176877 17949 log_reader.cc:385] T d7f77ff339584fa086a54df49bce0010: removed 2 log segments from log reader
I20260812 06:19:16.176921 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000001 (ops 1-6)
I20260812 06:19:16.176954 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000002 (ops 7-11)
I20260812 06:19:16.181427 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: LogGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:16.181943 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:16.204098 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.022s	user 0.013s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.204802 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:16.388453 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.183s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":10176,"lbm_reads_lt_1ms":454,"lbm_write_time_us":28801,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":556,"threads_started":5,"update_count":1950}
I20260812 06:19:16.389155 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010): 12719217 bytes on disk
I20260812 06:19:16.389684 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.390230 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:16.447965 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.058s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24162,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.448472 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:16.459358 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.459875 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:16.641914 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.182s	user 0.130s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":815,"lbm_read_time_us":9304,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38708,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:19:16.642778 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=11.118625
I20260812 06:19:16.688575 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":20775,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:16.689143 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:16.702507 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4639,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.703936 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:16.844040 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.140s	user 0.107s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":525,"lbm_read_time_us":11985,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24487,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:19:16.844650 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=10.126437
I20260812 06:19:16.895531 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.051s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15111,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.896147 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:16.911191 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.911881 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:17.061353 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.149s	user 0.124s	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":486,"lbm_read_time_us":10175,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29159,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":895360,"update_count":2000}
I20260812 06:19:17.063097 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=10.126437
I20260812 06:19:17.132059 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.069s	user 0.021s	sys 0.046s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26124,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.133038 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:17.152133 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.019s	user 0.016s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.153049 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:17.341938 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.189s	user 0.140s	sys 0.046s 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":851,"lbm_read_time_us":12796,"lbm_reads_lt_1ms":468,"lbm_write_time_us":31677,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:19:17.343236 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=11.118625
I20260812 06:19:17.390302 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.047s	user 0.031s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21107,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.391024 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:17.421408 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.030s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.422096 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:17.433401 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.434070 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:17.648720 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.214s	user 0.148s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":297,"lbm_read_time_us":11790,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37067,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2500}
I20260812 06:19:17.649400 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:17.707366 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.058s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26988,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.708249 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:17.719506 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.720224 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushMRSOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:17.757668 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushMRSOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.037s	user 0.032s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1711,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2296,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:17.758409 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling LogGCOp(d7f77ff339584fa086a54df49bce0010): free 124710298 bytes of WAL
I20260812 06:19:17.758728 17949 log_reader.cc:385] T d7f77ff339584fa086a54df49bce0010: removed 12 log segments from log reader
I20260812 06:19:17.758790 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000003 (ops 12-16)
I20260812 06:19:17.758828 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000004 (ops 17-21)
I20260812 06:19:17.758873 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000005 (ops 22-26)
I20260812 06:19:17.758909 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000006 (ops 27-31)
I20260812 06:19:17.758934 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000007 (ops 32-36)
I20260812 06:19:17.758955 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000008 (ops 37-41)
I20260812 06:19:17.758984 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000009 (ops 42-46)
I20260812 06:19:17.759016 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000010 (ops 47-51)
I20260812 06:19:17.759052 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000011 (ops 52-56)
I20260812 06:19:17.759083 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000012 (ops 57-61)
I20260812 06:19:17.759114 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000013 (ops 62-66)
I20260812 06:19:17.759143 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000014 (ops 67-71)
I20260812 06:19:17.792883 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: LogGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.034s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:17.793311 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010): 473 bytes on disk
I20260812 06:19:17.793722 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.794173 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=3.181125
I20260812 06:19:17.822721 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.028s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":5085,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:19:17.823298 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:17.840737 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":6480,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:17.841421 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:18.111457 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.270s	user 0.178s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1642,"lbm_read_time_us":17303,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41819,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13568,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:18.112690 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=18.063937
I20260812 06:19:18.202407 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.089s	user 0.034s	sys 0.040s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":34498,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.203061 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:18.216940 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.217566 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:18.445001 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.227s	user 0.142s	sys 0.082s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":16060,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37653,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:18.446123 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=15.087375
I20260812 06:19:18.503995 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.058s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":25487,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:19:18.504663 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:18.517419 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.013s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.517998 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:18.529279 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.529994 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:18.767083 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.237s	user 0.151s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":352,"lbm_read_time_us":14159,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40981,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":582016,"update_count":3000}
I20260812 06:19:18.767869 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=15.087375
I20260812 06:19:18.826757 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.059s	user 0.034s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24791,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:18.827345 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:18.847498 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6376,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.848142 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:19.026275 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.178s	user 0.119s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29844,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:19.027088 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:19.086897 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.060s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26885,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:19:19.087800 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:19.107010 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.019s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.107504 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:19.306262 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.199s	user 0.111s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":13726,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34497,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:19.307257 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=11.118625
I20260812 06:19:19.346120 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16423,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:19.346817 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:19.376519 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.030s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7058,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.377218 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushMRSOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:19.424270 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushMRSOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.047s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":124,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":2039,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1662,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:19.425496 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=3.181125
I20260812 06:19:19.440500 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4307780,"delete_count":0,"lbm_write_time_us":4589,"lbm_writes_lt_1ms":108,"mutex_wait_us":1,"reinsert_count":0,"update_count":525}
I20260812 06:19:19.440994 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling LogGCOp(d7f77ff339584fa086a54df49bce0010): free 120553339 bytes of WAL
I20260812 06:19:19.441215 17949 log_reader.cc:385] T d7f77ff339584fa086a54df49bce0010: removed 12 log segments from log reader
I20260812 06:19:19.441277 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000015 (ops 72-76)
I20260812 06:19:19.441332 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000016 (ops 77-81)
I20260812 06:19:19.441391 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000017 (ops 82-86)
I20260812 06:19:19.441437 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000018 (ops 87-90)
I20260812 06:19:19.441474 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000019 (ops 91-95)
I20260812 06:19:19.441515 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000020 (ops 96-100)
I20260812 06:19:19.441555 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000021 (ops 101-104)
I20260812 06:19:19.441594 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000022 (ops 105-109)
I20260812 06:19:19.441634 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000023 (ops 110-114)
I20260812 06:19:19.441674 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000024 (ops 115-119)
I20260812 06:19:19.441715 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000025 (ops 120-124)
I20260812 06:19:19.441752 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000026 (ops 125-129)
I20260812 06:19:19.471273 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: LogGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:19.472083 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010): 461 bytes on disk
I20260812 06:19:19.472750 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.473351 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=3.181125
I20260812 06:19:19.488979 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4307786,"delete_count":0,"lbm_write_time_us":4900,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:19.489482 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:19.503785 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.504433 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:19.762112 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.257s	user 0.181s	sys 0.062s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979855,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3555,"lbm_read_time_us":16845,"lbm_reads_lt_1ms":775,"lbm_write_time_us":45851,"lbm_writes_lt_1ms":743,"mutex_wait_us":2860,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:19:19.762903 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=18.063937
I20260812 06:19:19.827649 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.064s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":28490,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:19.828258 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:19.846465 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.847211 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:20.034502 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.187s	user 0.142s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":13372,"lbm_reads_lt_1ms":668,"lbm_write_time_us":37703,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":3000}
I20260812 06:19:20.035279 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:20.089649 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.054s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.090229 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:20.103358 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.103952 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:20.296200 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.192s	user 0.150s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":416,"lbm_read_time_us":11523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35567,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:20.297195 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:20.361457 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.064s	user 0.020s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29684,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.362013 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:20.528046 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.166s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":355,"lbm_read_time_us":10538,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24494,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:20.528988 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:20.596621 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.067s	user 0.038s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28921,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.597421 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:20.617144 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.617682 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:20.830950 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.213s	user 0.142s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1355,"lbm_read_time_us":13721,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38350,"lbm_writes_lt_1ms":543,"mutex_wait_us":453,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":49920,"update_count":2500}
I20260812 06:19:20.831475 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=11.118625
I20260812 06:19:20.870405 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.039s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16641,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:20.871018 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:20.888053 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:20.888738 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:21.030689 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.142s	user 0.105s	sys 0.036s 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":946,"lbm_read_time_us":8539,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28938,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":151808,"update_count":2000}
I20260812 06:19:21.031690 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=10.126437
I20260812 06:19:21.073587 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.039s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17529,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.074198 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:21.088342 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.089028 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushMRSOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:21.121981 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushMRSOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":794,"dirs.run_wall_time_us":2488,"drs_written":1,"lbm_read_time_us":150,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1859,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:21.123349 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling LogGCOp(d7f77ff339584fa086a54df49bce0010): free 121006757 bytes of WAL
I20260812 06:19:21.123684 17949 log_reader.cc:385] T d7f77ff339584fa086a54df49bce0010: removed 12 log segments from log reader
I20260812 06:19:21.123773 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000027 (ops 130-134)
I20260812 06:19:21.123840 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000028 (ops 135-139)
I20260812 06:19:21.123885 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000029 (ops 140-144)
I20260812 06:19:21.123932 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000030 (ops 145-149)
I20260812 06:19:21.123976 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000031 (ops 150-154)
I20260812 06:19:21.124018 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000032 (ops 155-159)
I20260812 06:19:21.124063 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000033 (ops 160-164)
I20260812 06:19:21.124104 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000034 (ops 165-168)
I20260812 06:19:21.124146 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000035 (ops 169-173)
I20260812 06:19:21.124266 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000036 (ops 174-178)
I20260812 06:19:21.124313 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000037 (ops 179-183)
I20260812 06:19:21.124353 17949 log.cc:1079] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: Deleting log segment in path: /tmp/dist-test-taskCfTDTS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515549704043-17617-0/minicluster-data/ts-0-root/wals/d7f77ff339584fa086a54df49bce0010/wal-000000038 (ops 184-188)
I20260812 06:19:21.153906 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: LogGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:21.154625 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010): 473 bytes on disk
I20260812 06:19:21.155198 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: UndoDeltaBlockGCOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.156136 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=5.165500
I20260812 06:19:21.184638 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.028s	user 0.021s	sys 0.006s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":12220,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:21.185534 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:21.195072 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":3256,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:21.195506 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:21.363835 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.168s	user 0.134s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":199,"lbm_read_time_us":11916,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33759,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:19:21.364593 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=14.095187
I20260812 06:19:21.408114 17617 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.530s	user 2.081s	sys 0.199s
I20260812 06:19:21.417766 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.053s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25403,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.418444 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010): perf score=2.188937
I20260812 06:19:21.430342 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: FlushDeltaMemStoresOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.430866 18017 maintenance_manager.cc:419] P 472e2ae756d34370b671a2b3b3db6b2a: Scheduling MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010): perf score=1.000000
I20260812 06:19:21.441780 17617 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.033s	user 0.001s	sys 0.000s
I20260812 06:19:21.442353 17617 tablet_server.cc:179] TabletServer@127.17.52.65:0 shutting down...
I20260812 06:19:21.554329 17949 maintenance_manager.cc:643] P 472e2ae756d34370b671a2b3b3db6b2a: MajorDeltaCompactionOp(d7f77ff339584fa086a54df49bce0010) complete. Timing: real 0.123s	user 0.094s	sys 0.029s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":634,"lbm_read_time_us":8410,"lbm_reads_lt_1ms":518,"lbm_write_time_us":23898,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52224,"update_count":2500}
I20260812 06:19:21.555018 17617 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:21.555263 17617 tablet_replica.cc:333] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a: stopping tablet replica
I20260812 06:19:21.555410 17617 raft_consensus.cc:2243] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.555603 17617 raft_consensus.cc:2272] T d7f77ff339584fa086a54df49bce0010 P 472e2ae756d34370b671a2b3b3db6b2a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.559587 17617 tablet_server.cc:196] TabletServer@127.17.52.65:0 shutdown complete.
I20260812 06:19:21.601068 17617 master.cc:562] Master@127.17.52.126:33127 shutting down...
I20260812 06:19:21.605036 17617 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.605237 17617 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.605291 17617 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1a2d14b1f88c48519596bf200fc56dd3: stopping tablet replica
I20260812 06:19:21.618069 17617 master.cc:584] Master@127.17.52.126:33127 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6081 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12001 ms total)

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