[==========] 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:01.911130 16142 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.195.190:32813
I20260812 06:19:01.912278 16142 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:01.912933 16142 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:01.919963 16151 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:01.920006 16142 server_base.cc:1061] running on GCE node
W20260812 06:19:01.919957 16152 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:01.920274 16155 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:01.920819 16142 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:01.920957 16142 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:01.921005 16142 hybrid_clock.cc:648] HybridClock initialized: now 1786515541921002 us; error 0 us; skew 500 ppm
I20260812 06:19:01.922816 16142 webserver.cc:533] Webserver started at http://127.15.195.190:41687/ using document root <none> and password file <none>
I20260812 06:19:01.923447 16142 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:01.923534 16142 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:01.923856 16142 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:01.925547 16142 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/master-0-root/instance:
uuid: "bcc77c8d5e5141c3a61adea477655376"
format_stamp: "Formatted at 2026-08-12 06:19:01 on dist-test-slave-7f01"
I20260812 06:19:01.929303 16142 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:01.931417 16163 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:01.932538 16142 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:01.932685 16142 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/master-0-root
uuid: "bcc77c8d5e5141c3a61adea477655376"
format_stamp: "Formatted at 2026-08-12 06:19:01 on dist-test-slave-7f01"
I20260812 06:19:01.932827 16142 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-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:01.949189 16142 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:01.949862 16142 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:01.950058 16142 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:01.958592 16142 rpc_server.cc:307] RPC server started. Bound to: 127.15.195.190:32813
I20260812 06:19:01.958601 16248 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.195.190:32813 every 8 connection(s)
I20260812 06:19:01.961459 16249 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:01.967907 16249 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: Bootstrap starting.
I20260812 06:19:01.970573 16249 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:01.971535 16249 log.cc:826] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:01.973454 16249 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: No bootstrap required, opened a new log
I20260812 06:19:01.976498 16249 raft_consensus.cc:359] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER }
I20260812 06:19:01.976684 16249 raft_consensus.cc:385] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:01.976727 16249 raft_consensus.cc:740] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bcc77c8d5e5141c3a61adea477655376, State: Initialized, Role: FOLLOWER
I20260812 06:19:01.977309 16249 consensus_queue.cc:260] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [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: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER }
I20260812 06:19:01.977447 16249 raft_consensus.cc:399] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:01.977509 16249 raft_consensus.cc:493] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:01.977594 16249 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:01.978366 16249 raft_consensus.cc:515] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER }
I20260812 06:19:01.978778 16249 leader_election.cc:304] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [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: bcc77c8d5e5141c3a61adea477655376; no voters: 
I20260812 06:19:01.979136 16249 leader_election.cc:290] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:01.979243 16254 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:01.979514 16254 raft_consensus.cc:697] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 1 LEADER]: Becoming Leader. State: Replica: bcc77c8d5e5141c3a61adea477655376, State: Running, Role: LEADER
I20260812 06:19:01.980078 16254 consensus_queue.cc:237] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [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: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER }
I20260812 06:19:01.980389 16249 sys_catalog.cc:565] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:01.982137 16258 sys_catalog.cc:455] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [sys.catalog]: SysCatalogTable state changed. Reason: New leader bcc77c8d5e5141c3a61adea477655376. Latest consensus state: current_term: 1 leader_uuid: "bcc77c8d5e5141c3a61adea477655376" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER } }
I20260812 06:19:01.982139 16257 sys_catalog.cc:455] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bcc77c8d5e5141c3a61adea477655376" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcc77c8d5e5141c3a61adea477655376" member_type: VOTER } }
I20260812 06:19:01.982291 16258 sys_catalog.cc:458] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:01.982297 16257 sys_catalog.cc:458] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:01.982792 16275 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:01.982983 16142 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:01.985740 16275 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:01.990818 16275 catalog_manager.cc:1383] Generated new cluster ID: b5a4cd1145ef4b5c802b78d661d39122
I20260812 06:19:01.990897 16275 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:02.014058 16275 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:02.015089 16275 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:02.022841 16275 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: Generated new TSK 0
I20260812 06:19:02.023524 16275 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:02.047809 16142 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:02.050726 16289 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:02.050832 16292 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:02.050935 16287 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:02.051230 16142 server_base.cc:1061] running on GCE node
I20260812 06:19:02.051468 16142 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:02.051522 16142 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:02.051539 16142 hybrid_clock.cc:648] HybridClock initialized: now 1786515542051539 us; error 0 us; skew 500 ppm
I20260812 06:19:02.052639 16142 webserver.cc:533] Webserver started at http://127.15.195.129:38325/ using document root <none> and password file <none>
I20260812 06:19:02.052829 16142 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:02.052881 16142 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:02.052946 16142 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:02.053345 16142 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/instance:
uuid: "19bdfe32a51849ada2ca1c4942887d8b"
format_stamp: "Formatted at 2026-08-12 06:19:02 on dist-test-slave-7f01"
I20260812 06:19:02.054955 16142 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:02.056049 16299 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:02.056910 16142 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:02.057008 16142 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root
uuid: "19bdfe32a51849ada2ca1c4942887d8b"
format_stamp: "Formatted at 2026-08-12 06:19:02 on dist-test-slave-7f01"
I20260812 06:19:02.057082 16142 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-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:02.087508 16142 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:02.088057 16142 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:02.088620 16142 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:02.089600 16142 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:02.089675 16142 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:02.089751 16142 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:02.089799 16142 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:02.096554 16142 rpc_server.cc:307] RPC server started. Bound to: 127.15.195.129:43075
I20260812 06:19:02.096588 16411 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.195.129:43075 every 8 connection(s)
I20260812 06:19:02.105934 16412 heartbeater.cc:344] Connected to a master server at 127.15.195.190:32813
I20260812 06:19:02.106170 16412 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:02.106586 16412 heartbeater.cc:507] Master 127.15.195.190:32813 requested a full tablet report, sending...
I20260812 06:19:02.108146 16194 ts_manager.cc:194] Registered new tserver with Master: 19bdfe32a51849ada2ca1c4942887d8b (127.15.195.129:43075)
I20260812 06:19:02.108451 16142 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011285842s
I20260812 06:19:02.109431 16194 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45166
I20260812 06:19:02.118500 16194 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45176:
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:02.133104 16344 tablet_service.cc:1511] Processing CreateTablet for tablet c2847031035049da8aeb8c5519fdf3f6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=dc4f0ecdc22e4141b1cb88843e05efc2]), partition=
I20260812 06:19:02.133584 16344 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c2847031035049da8aeb8c5519fdf3f6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:02.135959 16438 tablet_bootstrap.cc:492] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Bootstrap starting.
I20260812 06:19:02.137323 16438 tablet_bootstrap.cc:654] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:02.138550 16438 tablet_bootstrap.cc:492] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: No bootstrap required, opened a new log
I20260812 06:19:02.138635 16438 ts_tablet_manager.cc:1403] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:02.139129 16438 raft_consensus.cc:359] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19bdfe32a51849ada2ca1c4942887d8b" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 43075 } }
I20260812 06:19:02.139253 16438 raft_consensus.cc:385] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:02.139303 16438 raft_consensus.cc:740] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 19bdfe32a51849ada2ca1c4942887d8b, State: Initialized, Role: FOLLOWER
I20260812 06:19:02.139456 16438 consensus_queue.cc:260] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [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: "19bdfe32a51849ada2ca1c4942887d8b" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 43075 } }
I20260812 06:19:02.139550 16438 raft_consensus.cc:399] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:02.139597 16438 raft_consensus.cc:493] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:02.139650 16438 raft_consensus.cc:3060] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:02.140372 16438 raft_consensus.cc:515] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19bdfe32a51849ada2ca1c4942887d8b" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 43075 } }
I20260812 06:19:02.140530 16438 leader_election.cc:304] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [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: 19bdfe32a51849ada2ca1c4942887d8b; no voters: 
I20260812 06:19:02.140749 16438 leader_election.cc:290] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:02.140859 16440 raft_consensus.cc:2804] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:02.141077 16440 raft_consensus.cc:697] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 1 LEADER]: Becoming Leader. State: Replica: 19bdfe32a51849ada2ca1c4942887d8b, State: Running, Role: LEADER
I20260812 06:19:02.141175 16438 ts_tablet_manager.cc:1434] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:02.141237 16440 consensus_queue.cc:237] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [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: "19bdfe32a51849ada2ca1c4942887d8b" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 43075 } }
I20260812 06:19:02.141613 16412 heartbeater.cc:499] Master 127.15.195.190:32813 was elected leader, sending a full tablet report...
I20260812 06:19:02.144081 16194 catalog_manager.cc:5719] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b reported cstate change: term changed from 0 to 1, leader changed from <none> to 19bdfe32a51849ada2ca1c4942887d8b (127.15.195.129). New cstate: current_term: 1 leader_uuid: "19bdfe32a51849ada2ca1c4942887d8b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19bdfe32a51849ada2ca1c4942887d8b" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 43075 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:02.215705 16142 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.015s	sys 0.015s
I20260812 06:19:02.347694 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6): perf score=15.086190
I20260812 06:19:02.507910 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.160s	user 0.120s	sys 0.032s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":245,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1056,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39607,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":121,"threads_started":1,"update_count":1450}
I20260812 06:19:02.509140 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling LogGCOp(c2847031035049da8aeb8c5519fdf3f6): free 20743880 bytes of WAL
I20260812 06:19:02.509459 16310 log_reader.cc:385] T c2847031035049da8aeb8c5519fdf3f6: removed 2 log segments from log reader
I20260812 06:19:02.509536 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000001 (ops 1-6)
I20260812 06:19:02.509698 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000002 (ops 7-11)
I20260812 06:19:02.514309 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: LogGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:02.514624 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:02.531919 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.532400 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6): 12719216 bytes on disk
I20260812 06:19:02.532982 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:02.533402 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:02.666235 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.133s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":8266,"lbm_reads_lt_1ms":454,"lbm_write_time_us":24988,"lbm_writes_lt_1ms":433,"mutex_wait_us":22,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":304,"threads_started":5,"update_count":1950}
I20260812 06:19:02.666927 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:02.711128 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.044s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.711575 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:02.723658 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.726094 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:02.857884 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.132s	user 0.101s	sys 0.030s 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":277,"lbm_read_time_us":10020,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26134,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:02.858511 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:02.903437 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.045s	user 0.011s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15680,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.904007 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:02.915661 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.916251 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.047163 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.131s	user 0.094s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1754,"lbm_read_time_us":8862,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26615,"lbm_writes_lt_1ms":443,"mutex_wait_us":778,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2000}
I20260812 06:19:03.047885 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:03.098549 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.050s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19078,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.099140 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:03.110002 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.110467 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.262907 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.152s	user 0.100s	sys 0.052s 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":289,"lbm_read_time_us":12035,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24425,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:19:03.263638 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:03.307940 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.044s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14052,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.308456 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:03.319568 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.320369 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.446973 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.126s	user 0.098s	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":177,"lbm_read_time_us":9508,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23489,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:19:03.447669 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:03.495244 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.047s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15595,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.495779 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:03.506714 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.507390 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.627135 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.120s	user 0.096s	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":316,"lbm_read_time_us":8474,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23465,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.627869 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:03.680922 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.053s	user 0.032s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16898,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.681613 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:03.698944 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.699535 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.865064 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.165s	user 0.108s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":12830,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27626,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:03.865747 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:03.910362 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.044s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18377,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.910912 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:03.923223 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.923728 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:03.953104 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":316,"dirs.run_wall_time_us":1278,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1607,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:03.954067 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling LogGCOp(c2847031035049da8aeb8c5519fdf3f6): free 120553329 bytes of WAL
I20260812 06:19:03.954372 16310 log_reader.cc:385] T c2847031035049da8aeb8c5519fdf3f6: removed 12 log segments from log reader
I20260812 06:19:03.954442 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000003 (ops 12-16)
I20260812 06:19:03.954501 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000004 (ops 17-21)
I20260812 06:19:03.954566 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000005 (ops 22-26)
I20260812 06:19:03.954609 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000006 (ops 27-30)
I20260812 06:19:03.954650 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000007 (ops 31-35)
I20260812 06:19:03.954692 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000008 (ops 36-40)
I20260812 06:19:03.954733 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000009 (ops 41-45)
I20260812 06:19:03.954771 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000010 (ops 46-50)
I20260812 06:19:03.954814 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000011 (ops 51-55)
I20260812 06:19:03.954854 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000012 (ops 56-60)
I20260812 06:19:03.954895 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000013 (ops 61-64)
I20260812 06:19:03.954936 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000014 (ops 65-69)
I20260812 06:19:03.984529 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: LogGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:03.985061 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6): 483 bytes on disk
I20260812 06:19:03.985697 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:03.986234 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=3.181125
I20260812 06:19:04.013212 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.027s	user 0.016s	sys 0.009s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":7794,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:04.013654 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling LogGCOp(c2847031035049da8aeb8c5519fdf3f6): free 12017983 bytes of WAL
I20260812 06:19:04.013861 16310 log_reader.cc:385] T c2847031035049da8aeb8c5519fdf3f6: removed 1 log segments from log reader
I20260812 06:19:04.013906 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000015 (ops 70-74)
I20260812 06:19:04.016238 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: LogGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:04.016525 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:04.025229 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3302,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:04.025655 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:04.230854 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.205s	user 0.105s	sys 0.091s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":161,"lbm_read_time_us":15151,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34743,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"thread_start_us":102,"threads_started":1,"update_count":3000}
I20260812 06:19:04.231402 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=14.095187
I20260812 06:19:04.297499 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.066s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.298085 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:04.308907 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.309334 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:04.490170 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.181s	user 0.131s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":13601,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31643,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:19:04.490839 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:04.534493 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.043s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19073,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.535091 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:04.548058 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.550684 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:04.697916 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.147s	user 0.102s	sys 0.043s 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":378,"lbm_read_time_us":10005,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28041,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:04.698486 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:04.753288 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.055s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.753835 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:04.764659 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.765411 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:04.893486 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.128s	user 0.108s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1357,"lbm_read_time_us":9033,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23832,"lbm_writes_lt_1ms":443,"mutex_wait_us":364,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.894233 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:04.937211 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.043s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20950,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.937999 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:04.955729 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.956359 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:05.079969 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.123s	user 0.104s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":456,"lbm_read_time_us":8134,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24216,"lbm_writes_lt_1ms":443,"mutex_wait_us":333,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:19:05.080670 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:05.122997 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.042s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14270,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.123558 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:05.134127 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.134562 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:05.287281 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.153s	user 0.125s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":921,"lbm_read_time_us":11380,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25404,"lbm_writes_lt_1ms":443,"mutex_wait_us":261,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.290242 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:05.333362 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.043s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15474,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.333901 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:05.349465 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.350191 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:05.492164 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.142s	user 0.099s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":10487,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28084,"lbm_writes_lt_1ms":443,"mutex_wait_us":256,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:05.492841 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=10.126437
I20260812 06:19:05.541707 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.049s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17705,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.542232 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:05.553978 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.554524 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:05.583891 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.029s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1242,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1811,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:05.584667 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling LogGCOp(c2847031035049da8aeb8c5519fdf3f6): free 120553406 bytes of WAL
I20260812 06:19:05.584903 16310 log_reader.cc:385] T c2847031035049da8aeb8c5519fdf3f6: removed 12 log segments from log reader
I20260812 06:19:05.584947 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000016 (ops 75-79)
I20260812 06:19:05.584977 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000017 (ops 80-84)
I20260812 06:19:05.585041 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000018 (ops 85-89)
I20260812 06:19:05.585072 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000019 (ops 90-94)
I20260812 06:19:05.585111 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000020 (ops 95-99)
I20260812 06:19:05.585172 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000021 (ops 100-104)
I20260812 06:19:05.585211 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000022 (ops 105-109)
I20260812 06:19:05.585249 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000023 (ops 110-114)
I20260812 06:19:05.585287 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000024 (ops 115-118)
I20260812 06:19:05.585325 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000025 (ops 119-123)
I20260812 06:19:05.585363 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000026 (ops 124-128)
I20260812 06:19:05.585399 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000027 (ops 129-132)
I20260812 06:19:05.611538 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: LogGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:05.611979 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6): 482 bytes on disk
I20260812 06:19:05.612533 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: UndoDeltaBlockGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:05.613090 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=3.181125
I20260812 06:19:05.625929 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4923142,"delete_count":0,"lbm_write_time_us":5245,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:19:05.626353 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:05.638597 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:19:05.639058 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:05.806478 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.167s	user 0.120s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877319,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":519,"lbm_read_time_us":11702,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33071,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:19:05.807214 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=14.095187
I20260812 06:19:05.864012 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.056s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22080,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.864557 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:05.876626 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.877568 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:06.051349 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.173s	user 0.130s	sys 0.035s 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":387,"lbm_read_time_us":11465,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32041,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32128,"update_count":2500}
I20260812 06:19:06.051994 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=14.095187
I20260812 06:19:06.125730 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.074s	user 0.037s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29534,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.126204 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:06.137231 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.137943 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:06.324651 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.186s	user 0.121s	sys 0.057s 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":407,"lbm_read_time_us":11474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33286,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:06.325135 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=14.095187
I20260812 06:19:06.392261 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.067s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26451,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.392777 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:06.405303 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.406155 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:06.589943 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.184s	user 0.126s	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":587,"lbm_read_time_us":12241,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30815,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:19:06.590637 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=14.095187
I20260812 06:19:06.651258 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.060s	user 0.025s	sys 0.030s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21718,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.651926 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:06.663821 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4773,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.664306 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:06.855901 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.191s	user 0.104s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":13752,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34037,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:06.856480 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=11.118625
I20260812 06:19:06.894068 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16618,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:06.894804 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:06.931061 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.036s	user 0.007s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6280,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.931561 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=2.188937
I20260812 06:19:06.942625 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4409,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.943092 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:07.135865 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.193s	user 0.140s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":852,"dirs.run_cpu_time_us":508,"dirs.run_wall_time_us":2676,"lbm_read_time_us":13520,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29410,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:07.136961 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=11.118625
I20260812 06:19:07.178143 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.041s	user 0.027s	sys 0.012s Metrics: {"bytes_written":13251055,"delete_count":0,"lbm_write_time_us":18380,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:19:07.178836 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.196750
I20260812 06:19:07.192829 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":5031,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:07.193377 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:07.246757 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushMRSOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.053s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1912,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:07.248227 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6): perf score=6.157687
I20260812 06:19:07.276860 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: FlushDeltaMemStoresOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.028s	user 0.017s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12430,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:07.277437 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling LogGCOp(c2847031035049da8aeb8c5519fdf3f6): free 129773845 bytes of WAL
I20260812 06:19:07.277716 16310 log_reader.cc:385] T c2847031035049da8aeb8c5519fdf3f6: removed 13 log segments from log reader
I20260812 06:19:07.277791 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000028 (ops 133-137)
I20260812 06:19:07.277848 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000029 (ops 138-142)
I20260812 06:19:07.277906 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000030 (ops 143-147)
I20260812 06:19:07.277940 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000031 (ops 148-152)
I20260812 06:19:07.277978 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000032 (ops 153-157)
I20260812 06:19:07.278017 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000033 (ops 158-162)
I20260812 06:19:07.278055 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000034 (ops 163-167)
I20260812 06:19:07.278095 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000035 (ops 168-172)
I20260812 06:19:07.278133 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000036 (ops 173-177)
I20260812 06:19:07.278172 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000037 (ops 178-182)
I20260812 06:19:07.278210 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000038 (ops 183-186)
I20260812 06:19:07.278247 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000039 (ops 187-191)
I20260812 06:19:07.278287 16310 log.cc:1079] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/c2847031035049da8aeb8c5519fdf3f6/wal-000000040 (ops 192-196)
I20260812 06:19:07.306249 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: LogGCOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:07.306748 16413 maintenance_manager.cc:419] P 19bdfe32a51849ada2ca1c4942887d8b: Scheduling MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6): perf score=1.000000
I20260812 06:19:07.329846 16142 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.114s	user 1.917s	sys 0.150s
I20260812 06:19:07.429595 16142 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.002s	sys 0.000s
I20260812 06:19:07.430361 16142 tablet_server.cc:179] TabletServer@127.15.195.129:0 shutting down...
I20260812 06:19:07.488062 16310 maintenance_manager.cc:643] P 19bdfe32a51849ada2ca1c4942887d8b: MajorDeltaCompactionOp(c2847031035049da8aeb8c5519fdf3f6) complete. Timing: real 0.181s	user 0.122s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":393,"lbm_read_time_us":16706,"lbm_reads_lt_1ms":661,"lbm_write_time_us":31206,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:07.488911 16142 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:07.489420 16142 tablet_replica.cc:333] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b: stopping tablet replica
I20260812 06:19:07.489684 16142 raft_consensus.cc:2243] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:07.489940 16142 raft_consensus.cc:2272] T c2847031035049da8aeb8c5519fdf3f6 P 19bdfe32a51849ada2ca1c4942887d8b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:07.505985 16142 tablet_server.cc:196] TabletServer@127.15.195.129:0 shutdown complete.
I20260812 06:19:07.538798 16142 master.cc:562] Master@127.15.195.190:32813 shutting down...
I20260812 06:19:07.543488 16142 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:07.543695 16142 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:07.543809 16142 tablet_replica.cc:333] T 00000000000000000000000000000000 P bcc77c8d5e5141c3a61adea477655376: stopping tablet replica
I20260812 06:19:07.556257 16142 master.cc:584] Master@127.15.195.190:32813 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5739 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:07.666246 16142 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.195.190:33291
I20260812 06:19:07.666739 16142 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:07.668952 16462 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:07.669106 16463 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:07.669128 16142 server_base.cc:1061] running on GCE node
W20260812 06:19:07.669100 16466 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:07.669534 16142 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:07.669584 16142 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:07.669602 16142 hybrid_clock.cc:648] HybridClock initialized: now 1786515547669602 us; error 0 us; skew 500 ppm
I20260812 06:19:07.670535 16142 webserver.cc:533] Webserver started at http://127.15.195.190:46791/ using document root <none> and password file <none>
I20260812 06:19:07.670743 16142 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:07.670814 16142 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:07.670905 16142 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:07.671361 16142 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/master-0-root/instance:
uuid: "a4cab68a72a54c3c8d1383896d3cbed7"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-7f01"
I20260812 06:19:07.673125 16142 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:07.674317 16482 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:07.674597 16142 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:07.674670 16142 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/master-0-root
uuid: "a4cab68a72a54c3c8d1383896d3cbed7"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-7f01"
I20260812 06:19:07.674774 16142 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-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:07.684362 16142 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:07.684729 16142 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:07.689468 16142 rpc_server.cc:307] RPC server started. Bound to: 127.15.195.190:33291
I20260812 06:19:07.693981 16572 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.195.190:33291 every 8 connection(s)
I20260812 06:19:07.694460 16574 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:07.696476 16574 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7: Bootstrap starting.
I20260812 06:19:07.697301 16574 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:07.698336 16574 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7: No bootstrap required, opened a new log
I20260812 06:19:07.698704 16574 raft_consensus.cc:359] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER }
I20260812 06:19:07.698792 16574 raft_consensus.cc:385] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:07.698817 16574 raft_consensus.cc:740] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a4cab68a72a54c3c8d1383896d3cbed7, State: Initialized, Role: FOLLOWER
I20260812 06:19:07.698980 16574 consensus_queue.cc:260] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [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: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER }
I20260812 06:19:07.699075 16574 raft_consensus.cc:399] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:07.699103 16574 raft_consensus.cc:493] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:07.699142 16574 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:07.699864 16574 raft_consensus.cc:515] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER }
I20260812 06:19:07.700003 16574 leader_election.cc:304] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [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: a4cab68a72a54c3c8d1383896d3cbed7; no voters: 
I20260812 06:19:07.700152 16574 leader_election.cc:290] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:07.700281 16578 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:07.700470 16578 raft_consensus.cc:697] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 1 LEADER]: Becoming Leader. State: Replica: a4cab68a72a54c3c8d1383896d3cbed7, State: Running, Role: LEADER
I20260812 06:19:07.700613 16578 consensus_queue.cc:237] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [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: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER }
I20260812 06:19:07.700644 16574 sys_catalog.cc:565] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:07.701073 16579 sys_catalog.cc:455] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER } }
I20260812 06:19:07.701088 16585 sys_catalog.cc:455] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a4cab68a72a54c3c8d1383896d3cbed7. Latest consensus state: current_term: 1 leader_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4cab68a72a54c3c8d1383896d3cbed7" member_type: VOTER } }
I20260812 06:19:07.701195 16585 sys_catalog.cc:458] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:07.701488 16588 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:07.702543 16588 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:07.702780 16142 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:07.701465 16579 sys_catalog.cc:458] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:07.704365 16588 catalog_manager.cc:1383] Generated new cluster ID: dbb3e53fb1634e7690703e8f5e6477bc
I20260812 06:19:07.704423 16588 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:07.723088 16588 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:07.723614 16588 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:07.739848 16588 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7: Generated new TSK 0
I20260812 06:19:07.740001 16588 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:07.767310 16142 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:07.769493 16612 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:07.769596 16142 server_base.cc:1061] running on GCE node
W20260812 06:19:07.769645 16610 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:07.769493 16609 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:07.769987 16142 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:07.770035 16142 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:07.770051 16142 hybrid_clock.cc:648] HybridClock initialized: now 1786515547770051 us; error 0 us; skew 500 ppm
I20260812 06:19:07.770967 16142 webserver.cc:533] Webserver started at http://127.15.195.129:42061/ using document root <none> and password file <none>
I20260812 06:19:07.771106 16142 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:07.771152 16142 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:07.771204 16142 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:07.771550 16142 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/instance:
uuid: "53b0821e14244db6b3878151011be5b2"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-7f01"
I20260812 06:19:07.773087 16142 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:07.774005 16622 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:07.774291 16142 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:07.774358 16142 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root
uuid: "53b0821e14244db6b3878151011be5b2"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-7f01"
I20260812 06:19:07.774410 16142 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-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:07.785756 16142 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:07.786028 16142 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:07.786255 16142 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:07.786700 16142 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:07.786738 16142 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.786816 16142 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:07.786854 16142 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.791215 16142 rpc_server.cc:307] RPC server started. Bound to: 127.15.195.129:45385
I20260812 06:19:07.793233 16741 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.195.129:45385 every 8 connection(s)
I20260812 06:19:07.800732 16742 heartbeater.cc:344] Connected to a master server at 127.15.195.190:33291
I20260812 06:19:07.800866 16742 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:07.801137 16742 heartbeater.cc:507] Master 127.15.195.190:33291 requested a full tablet report, sending...
I20260812 06:19:07.801837 16509 ts_manager.cc:194] Registered new tserver with Master: 53b0821e14244db6b3878151011be5b2 (127.15.195.129:45385)
I20260812 06:19:07.802279 16142 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010108924s
I20260812 06:19:07.802676 16509 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56488
I20260812 06:19:07.809417 16509 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56494:
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:07.821137 16682 tablet_service.cc:1511] Processing CreateTablet for tablet 90597ec73df44061873b80390285b2be (DEFAULT_TABLE table=heavy-update-compaction-test [id=2c08fbf8e24248d88ca6c8c543a1d2c1]), partition=
I20260812 06:19:07.821452 16682 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 90597ec73df44061873b80390285b2be. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:07.823709 16762 tablet_bootstrap.cc:492] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Bootstrap starting.
I20260812 06:19:07.824577 16762 tablet_bootstrap.cc:654] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:07.825590 16762 tablet_bootstrap.cc:492] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: No bootstrap required, opened a new log
I20260812 06:19:07.825680 16762 ts_tablet_manager.cc:1403] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:07.826040 16762 raft_consensus.cc:359] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53b0821e14244db6b3878151011be5b2" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 45385 } }
I20260812 06:19:07.826155 16762 raft_consensus.cc:385] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:07.826191 16762 raft_consensus.cc:740] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 53b0821e14244db6b3878151011be5b2, State: Initialized, Role: FOLLOWER
I20260812 06:19:07.826344 16762 consensus_queue.cc:260] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [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: "53b0821e14244db6b3878151011be5b2" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 45385 } }
I20260812 06:19:07.826467 16762 raft_consensus.cc:399] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:07.826515 16762 raft_consensus.cc:493] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:07.826567 16762 raft_consensus.cc:3060] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:07.827319 16762 raft_consensus.cc:515] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53b0821e14244db6b3878151011be5b2" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 45385 } }
I20260812 06:19:07.827476 16762 leader_election.cc:304] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [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: 53b0821e14244db6b3878151011be5b2; no voters: 
I20260812 06:19:07.827683 16762 leader_election.cc:290] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:07.827858 16768 raft_consensus.cc:2804] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:07.828079 16742 heartbeater.cc:499] Master 127.15.195.190:33291 was elected leader, sending a full tablet report...
I20260812 06:19:07.828091 16768 raft_consensus.cc:697] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 1 LEADER]: Becoming Leader. State: Replica: 53b0821e14244db6b3878151011be5b2, State: Running, Role: LEADER
I20260812 06:19:07.828130 16762 ts_tablet_manager.cc:1434] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:07.828233 16768 consensus_queue.cc:237] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [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: "53b0821e14244db6b3878151011be5b2" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 45385 } }
I20260812 06:19:07.829527 16509 catalog_manager.cc:5719] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 53b0821e14244db6b3878151011be5b2 (127.15.195.129). New cstate: current_term: 1 leader_uuid: "53b0821e14244db6b3878151011be5b2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53b0821e14244db6b3878151011be5b2" member_type: VOTER last_known_addr { host: "127.15.195.129" port: 45385 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:07.895279 16142 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.015s	sys 0.008s
I20260812 06:19:08.043721 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushMRSOp(90597ec73df44061873b80390285b2be): perf score=19.054940
I20260812 06:19:08.203244 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushMRSOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.159s	user 0.107s	sys 0.044s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":154,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":826,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40905,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:08.203927 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling LogGCOp(90597ec73df44061873b80390285b2be): free 20743831 bytes of WAL
I20260812 06:19:08.204138 16644 log_reader.cc:385] T 90597ec73df44061873b80390285b2be: removed 2 log segments from log reader
I20260812 06:19:08.204224 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000001 (ops 1-6)
I20260812 06:19:08.204280 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000002 (ops 7-11)
I20260812 06:19:08.208699 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: LogGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:08.209015 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:08.219911 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.220468 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:08.383258 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.163s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":11156,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26261,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":352,"threads_started":5,"update_count":2000}
I20260812 06:19:08.383874 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be): 16411394 bytes on disk
I20260812 06:19:08.384351 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.384871 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:08.420385 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.035s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15929,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.420890 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:08.432710 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.433379 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:08.565042 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.131s	user 0.095s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1070,"lbm_read_time_us":9561,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24212,"lbm_writes_lt_1ms":443,"mutex_wait_us":351,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:19:08.565683 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:08.605541 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.040s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17262,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.606035 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:08.619324 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.619978 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:08.750674 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.130s	user 0.118s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":9737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26377,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:08.751490 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:08.796329 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.045s	user 0.016s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17952,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.796801 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:08.807981 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.808661 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:08.947700 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.139s	user 0.094s	sys 0.044s 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":1172,"lbm_read_time_us":10326,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27016,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":257280,"update_count":2000}
I20260812 06:19:08.948638 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:09.006294 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.057s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16764,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.006902 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:09.018671 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.019148 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:09.186439 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.167s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":12692,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26226,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:09.187089 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:09.229733 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.042s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.230309 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:09.249279 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.249740 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:09.385416 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.135s	user 0.115s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1124,"lbm_read_time_us":10183,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24941,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:09.385993 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=10.126437
I20260812 06:19:09.427137 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.041s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.427664 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:09.439971 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.440420 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushMRSOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:09.469276 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushMRSOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1229,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1510,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:09.469870 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling LogGCOp(90597ec73df44061873b80390285b2be): free 112692416 bytes of WAL
I20260812 06:19:09.470103 16644 log_reader.cc:385] T 90597ec73df44061873b80390285b2be: removed 11 log segments from log reader
I20260812 06:19:09.470147 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000003 (ops 12-16)
I20260812 06:19:09.470176 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000004 (ops 17-21)
I20260812 06:19:09.470219 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000005 (ops 22-26)
I20260812 06:19:09.470261 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000006 (ops 27-31)
I20260812 06:19:09.470292 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000007 (ops 32-36)
I20260812 06:19:09.470310 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000008 (ops 37-41)
I20260812 06:19:09.470366 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000009 (ops 42-46)
I20260812 06:19:09.470391 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000010 (ops 47-51)
I20260812 06:19:09.470418 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000011 (ops 52-56)
I20260812 06:19:09.470459 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000012 (ops 57-61)
I20260812 06:19:09.470490 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000013 (ops 62-66)
I20260812 06:19:09.497414 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: LogGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:09.497862 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be): 447 bytes on disk
I20260812 06:19:09.498458 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be) 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:09.498940 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=6.157687
I20260812 06:19:09.519500 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":7466641,"delete_count":0,"lbm_write_time_us":7945,"lbm_writes_lt_1ms":185,"reinsert_count":0,"update_count":910}
I20260812 06:19:09.519994 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:09.691964 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.172s	user 0.137s	sys 0.033s Metrics: {"cfile_cache_miss":615,"cfile_cache_miss_bytes":28138786,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1379,"lbm_read_time_us":12765,"lbm_reads_lt_1ms":651,"lbm_write_time_us":32749,"lbm_writes_lt_1ms":625,"mutex_wait_us":45,"peak_mem_usage":72723074,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":118,"threads_started":1,"update_count":2910}
I20260812 06:19:09.692610 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=15.087375
I20260812 06:19:09.739080 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.046s	user 0.028s	sys 0.015s Metrics: {"bytes_written":17148341,"delete_count":0,"lbm_write_time_us":20744,"lbm_writes_lt_1ms":421,"reinsert_count":0,"update_count":2090}
I20260812 06:19:09.739642 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:09.757754 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.018s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.758399 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:09.930321 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.172s	user 0.141s	sys 0.024s Metrics: {"cfile_cache_miss":550,"cfile_cache_miss_bytes":25513128,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":11218,"lbm_reads_lt_1ms":586,"lbm_write_time_us":32687,"lbm_writes_lt_1ms":561,"mutex_wait_us":314,"peak_mem_usage":64894914,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2590}
I20260812 06:19:09.931070 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:09.991621 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.060s	user 0.044s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24541,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.992269 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:10.004258 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.006582 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:10.179145 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.172s	user 0.137s	sys 0.024s 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":248,"lbm_read_time_us":9694,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32873,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:10.180025 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:10.234548 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.054s	user 0.026s	sys 0.018s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.235117 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:10.247159 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.009s	sys 0.000s 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:10.247674 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:10.416129 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.168s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":765,"lbm_read_time_us":12732,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31069,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:10.416863 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=13.103000
I20260812 06:19:10.470624 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.054s	user 0.025s	sys 0.022s Metrics: {"bytes_written":14563813,"delete_count":0,"lbm_write_time_us":22319,"lbm_writes_lt_1ms":358,"reinsert_count":0,"update_count":1775}
I20260812 06:19:10.471170 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=1.196750
I20260812 06:19:10.497972 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.027s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2256533,"delete_count":0,"lbm_write_time_us":2928,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:19:10.500204 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:10.515331 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5516,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.516156 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:10.701236 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.185s	user 0.132s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":153,"lbm_read_time_us":12785,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31559,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:10.701989 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:10.763136 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.061s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21882,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.763826 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:10.774745 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.775231 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:10.953730 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.178s	user 0.114s	sys 0.064s 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":621,"lbm_read_time_us":12725,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30904,"lbm_writes_lt_1ms":543,"mutex_wait_us":257,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:10.954344 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:11.012223 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.058s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21554,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.012807 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:11.023562 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.024055 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushMRSOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:11.066159 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushMRSOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.042s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1329,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1575,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:11.066900 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling LogGCOp(90597ec73df44061873b80390285b2be): free 132571275 bytes of WAL
I20260812 06:19:11.067142 16644 log_reader.cc:385] T 90597ec73df44061873b80390285b2be: removed 13 log segments from log reader
I20260812 06:19:11.067191 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000014 (ops 67-70)
I20260812 06:19:11.067220 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000015 (ops 71-75)
I20260812 06:19:11.067282 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000016 (ops 76-80)
I20260812 06:19:11.067315 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000017 (ops 81-85)
I20260812 06:19:11.067370 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000018 (ops 86-90)
I20260812 06:19:11.067390 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000019 (ops 91-95)
I20260812 06:19:11.067446 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000020 (ops 96-100)
I20260812 06:19:11.067487 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000021 (ops 101-104)
I20260812 06:19:11.067525 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000022 (ops 105-109)
I20260812 06:19:11.067564 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000023 (ops 110-114)
I20260812 06:19:11.067605 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000024 (ops 115-119)
I20260812 06:19:11.067644 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000025 (ops 120-124)
I20260812 06:19:11.067683 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000026 (ops 125-129)
I20260812 06:19:11.097023 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: LogGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:11.097484 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=3.181125
I20260812 06:19:11.121109 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.023s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7693,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:11.121619 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be): 492 bytes on disk
I20260812 06:19:11.122010 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: UndoDeltaBlockGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.122499 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:11.132473 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3851,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.132987 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:11.380728 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.248s	user 0.167s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":588,"lbm_read_time_us":15793,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43557,"lbm_writes_lt_1ms":743,"mutex_wait_us":274,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:11.381487 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=15.087375
I20260812 06:19:11.441278 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.060s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":20515,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:11.441725 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=6.157687
I20260812 06:19:11.464555 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.023s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9324,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:11.465106 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:11.632387 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.167s	user 0.114s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":963,"lbm_read_time_us":11211,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32214,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:11.633265 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:11.707378 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.074s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":43232,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.707939 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=3.181125
I20260812 06:19:11.730082 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.022s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6965,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:11.730541 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:11.740090 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3768,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.740548 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:11.937498 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.197s	user 0.117s	sys 0.070s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":718,"lbm_read_time_us":14449,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38117,"lbm_writes_lt_1ms":643,"mutex_wait_us":16,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":3000}
I20260812 06:19:11.938138 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:11.997836 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.060s	user 0.045s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":30416,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.998308 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:12.010218 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.010691 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:12.182493 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.172s	user 0.133s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1151,"lbm_read_time_us":13144,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33584,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":2500}
I20260812 06:19:12.183094 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=11.118625
I20260812 06:19:12.229879 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.047s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20006,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.230448 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:12.254284 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.024s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3957,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.254801 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:12.269833 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.270354 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:12.473825 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.203s	user 0.140s	sys 0.051s 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":369,"lbm_read_time_us":15081,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32009,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":73984,"update_count":2500}
I20260812 06:19:12.474632 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=14.095187
I20260812 06:19:12.534143 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.059s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.534672 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:12.545768 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.546319 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushMRSOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:12.579372 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushMRSOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.033s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1434,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1514,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":1792}
I20260812 06:19:12.580196 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling LogGCOp(90597ec73df44061873b80390285b2be): free 120553690 bytes of WAL
I20260812 06:19:12.580451 16644 log_reader.cc:385] T 90597ec73df44061873b80390285b2be: removed 12 log segments from log reader
I20260812 06:19:12.580519 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000027 (ops 130-134)
I20260812 06:19:12.580574 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000028 (ops 135-138)
I20260812 06:19:12.580614 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000029 (ops 139-143)
I20260812 06:19:12.580653 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000030 (ops 144-148)
I20260812 06:19:12.580691 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000031 (ops 149-153)
I20260812 06:19:12.580730 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000032 (ops 154-158)
I20260812 06:19:12.580770 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000033 (ops 159-162)
I20260812 06:19:12.580808 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000034 (ops 163-167)
I20260812 06:19:12.580848 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000035 (ops 168-172)
I20260812 06:19:12.580896 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000036 (ops 173-177)
I20260812 06:19:12.580936 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000037 (ops 178-182)
I20260812 06:19:12.580976 16644 log.cc:1079] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: Deleting log segment in path: /tmp/dist-test-taskXuIMPJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515541900278-16142-0/minicluster-data/ts-0-root/wals/90597ec73df44061873b80390285b2be/wal-000000038 (ops 183-187)
I20260812 06:19:12.607833 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: LogGCOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:12.608376 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=3.181125
I20260812 06:19:12.625563 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.017s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:12.626035 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=2.188937
I20260812 06:19:12.636029 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.636474 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be): perf score=1.000000
I20260812 06:19:12.869175 16142 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.974s	user 1.880s	sys 0.124s
I20260812 06:19:12.872328 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: MajorDeltaCompactionOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.236s	user 0.173s	sys 0.053s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":896,"lbm_read_time_us":16698,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41449,"lbm_writes_lt_1ms":743,"mutex_wait_us":551,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:12.873087 16744 maintenance_manager.cc:419] P 53b0821e14244db6b3878151011be5b2: Scheduling FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be): perf score=18.063937
I20260812 06:19:12.906208 16142 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.037s	user 0.004s	sys 0.000s
I20260812 06:19:12.906947 16142 tablet_server.cc:179] TabletServer@127.15.195.129:0 shutting down...
I20260812 06:19:12.944525 16644 maintenance_manager.cc:643] P 53b0821e14244db6b3878151011be5b2: FlushDeltaMemStoresOp(90597ec73df44061873b80390285b2be) complete. Timing: real 0.071s	user 0.042s	sys 0.021s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28420,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:12.945122 16142 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:12.945374 16142 tablet_replica.cc:333] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2: stopping tablet replica
I20260812 06:19:12.945644 16142 raft_consensus.cc:2243] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:12.945837 16142 raft_consensus.cc:2272] T 90597ec73df44061873b80390285b2be P 53b0821e14244db6b3878151011be5b2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:12.949322 16142 tablet_server.cc:196] TabletServer@127.15.195.129:0 shutdown complete.
I20260812 06:19:12.952077 16142 master.cc:562] Master@127.15.195.190:33291 shutting down...
I20260812 06:19:12.955281 16142 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:12.955430 16142 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:12.955479 16142 tablet_replica.cc:333] T 00000000000000000000000000000000 P a4cab68a72a54c3c8d1383896d3cbed7: stopping tablet replica
I20260812 06:19:12.967494 16142 master.cc:584] Master@127.15.195.190:33291 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5406 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11147 ms total)

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