[==========] 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:17:41.403523  2473 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.106.126:46077
I20260812 06:17:41.404608  2473 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:17:41.405216  2473 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:41.411893  2479 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:17:41.411911  2473 server_base.cc:1061] running on GCE node
W20260812 06:17:41.412017  2481 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:17:41.412146  2478 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:17:41.412706  2473 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:41.412832  2473 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:17:41.412886  2473 hybrid_clock.cc:648] HybridClock initialized: now 1786515461412882 us; error 0 us; skew 500 ppm
I20260812 06:17:41.414847  2473 webserver.cc:533] Webserver started at http://127.2.106.126:44123/ using document root <none> and password file <none>
I20260812 06:17:41.415449  2473 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:41.415537  2473 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:41.415795  2473 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:41.417528  2473 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/master-0-root/instance:
uuid: "3c5664786e6e444faf2908427c58c56f"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-zpfg"
I20260812 06:17:41.421170  2473 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:41.423580  2486 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:17:41.424847  2473 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:41.424991  2473 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/master-0-root
uuid: "3c5664786e6e444faf2908427c58c56f"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-zpfg"
I20260812 06:17:41.425134  2473 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-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:17:41.441027  2473 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:41.441757  2473 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:17:41.441953  2473 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:41.449609  2473 rpc_server.cc:307] RPC server started. Bound to: 127.2.106.126:46077
I20260812 06:17:41.449618  2543 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.106.126:46077 every 8 connection(s)
I20260812 06:17:41.451889  2544 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:17:41.457297  2544 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: Bootstrap starting.
I20260812 06:17:41.459762  2544 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:41.460700  2544 log.cc:826] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:41.462492  2544 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: No bootstrap required, opened a new log
I20260812 06:17:41.465698  2544 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER }
I20260812 06:17:41.465878  2544 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:41.465969  2544 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c5664786e6e444faf2908427c58c56f, State: Initialized, Role: FOLLOWER
I20260812 06:17:41.466660  2544 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [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: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER }
I20260812 06:17:41.466835  2544 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:41.466917  2544 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:41.467044  2544 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:41.467907  2544 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER }
I20260812 06:17:41.468382  2544 leader_election.cc:304] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [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: 3c5664786e6e444faf2908427c58c56f; no voters: 
I20260812 06:17:41.468711  2544 leader_election.cc:290] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:41.468887  2547 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:41.469137  2547 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 1 LEADER]: Becoming Leader. State: Replica: 3c5664786e6e444faf2908427c58c56f, State: Running, Role: LEADER
I20260812 06:17:41.469594  2547 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [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: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER }
I20260812 06:17:41.469841  2544 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:41.471590  2549 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3c5664786e6e444faf2908427c58c56f. Latest consensus state: current_term: 1 leader_uuid: "3c5664786e6e444faf2908427c58c56f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER } }
I20260812 06:17:41.471630  2548 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3c5664786e6e444faf2908427c58c56f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c5664786e6e444faf2908427c58c56f" member_type: VOTER } }
I20260812 06:17:41.471714  2549 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:41.471721  2548 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:41.472108  2556 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:41.474757  2556 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:41.475024  2473 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:41.479987  2556 catalog_manager.cc:1383] Generated new cluster ID: d2ca2f8a4a094a11aadcf092778d7e2a
I20260812 06:17:41.480063  2556 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:41.487690  2556 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:41.488560  2556 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:41.495488  2556 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: Generated new TSK 0
I20260812 06:17:41.496162  2556 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:41.507851  2473 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:41.511503  2567 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:17:41.511551  2568 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:17:41.511696  2473 server_base.cc:1061] running on GCE node
W20260812 06:17:41.511574  2570 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:17:41.512018  2473 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:41.512063  2473 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:17:41.512077  2473 hybrid_clock.cc:648] HybridClock initialized: now 1786515461512078 us; error 0 us; skew 500 ppm
I20260812 06:17:41.513037  2473 webserver.cc:533] Webserver started at http://127.2.106.65:40145/ using document root <none> and password file <none>
I20260812 06:17:41.513229  2473 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:41.513279  2473 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:41.513376  2473 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:41.513778  2473 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/instance:
uuid: "548094e8e3d94baf82afcb0d1be79157"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-zpfg"
I20260812 06:17:41.515362  2473 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:41.516390  2575 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:17:41.516628  2473 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:41.516700  2473 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root
uuid: "548094e8e3d94baf82afcb0d1be79157"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-zpfg"
I20260812 06:17:41.516794  2473 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-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:17:41.532397  2473 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:41.533106  2473 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:41.533653  2473 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:41.534653  2473 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:41.534708  2473 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.534773  2473 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:41.534821  2473 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.541838  2473 rpc_server.cc:307] RPC server started. Bound to: 127.2.106.65:39469
I20260812 06:17:41.541864  2646 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.106.65:39469 every 8 connection(s)
I20260812 06:17:41.552177  2647 heartbeater.cc:344] Connected to a master server at 127.2.106.126:46077
I20260812 06:17:41.552459  2647 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:41.552953  2647 heartbeater.cc:507] Master 127.2.106.126:46077 requested a full tablet report, sending...
I20260812 06:17:41.554555  2505 ts_manager.cc:194] Registered new tserver with Master: 548094e8e3d94baf82afcb0d1be79157 (127.2.106.65:39469)
I20260812 06:17:41.554885  2473 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012312665s
I20260812 06:17:41.556716  2505 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36978
I20260812 06:17:41.565659  2505 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36994:
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:17:41.583037  2607 tablet_service.cc:1511] Processing CreateTablet for tablet ff6889db132c4d14bd89f930ca1736f5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=aa019dd8ddbf4894ab55be58e7668fb3]), partition=
I20260812 06:17:41.583534  2607 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ff6889db132c4d14bd89f930ca1736f5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:41.585896  2660 tablet_bootstrap.cc:492] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Bootstrap starting.
I20260812 06:17:41.586908  2660 tablet_bootstrap.cc:654] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:41.588338  2660 tablet_bootstrap.cc:492] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: No bootstrap required, opened a new log
I20260812 06:17:41.588498  2660 ts_tablet_manager.cc:1403] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:41.589053  2660 raft_consensus.cc:359] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "548094e8e3d94baf82afcb0d1be79157" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 39469 } }
I20260812 06:17:41.589167  2660 raft_consensus.cc:385] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:41.589320  2660 raft_consensus.cc:740] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 548094e8e3d94baf82afcb0d1be79157, State: Initialized, Role: FOLLOWER
I20260812 06:17:41.589500  2660 consensus_queue.cc:260] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [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: "548094e8e3d94baf82afcb0d1be79157" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 39469 } }
I20260812 06:17:41.589651  2660 raft_consensus.cc:399] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:41.589726  2660 raft_consensus.cc:493] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:41.589795  2660 raft_consensus.cc:3060] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:41.590775  2660 raft_consensus.cc:515] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "548094e8e3d94baf82afcb0d1be79157" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 39469 } }
I20260812 06:17:41.590946  2660 leader_election.cc:304] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [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: 548094e8e3d94baf82afcb0d1be79157; no voters: 
I20260812 06:17:41.591229  2660 leader_election.cc:290] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:41.591347  2662 raft_consensus.cc:2804] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:41.591559  2662 raft_consensus.cc:697] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 1 LEADER]: Becoming Leader. State: Replica: 548094e8e3d94baf82afcb0d1be79157, State: Running, Role: LEADER
I20260812 06:17:41.591696  2660 ts_tablet_manager.cc:1434] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:17:41.591799  2662 consensus_queue.cc:237] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [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: "548094e8e3d94baf82afcb0d1be79157" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 39469 } }
I20260812 06:17:41.591892  2647 heartbeater.cc:499] Master 127.2.106.126:46077 was elected leader, sending a full tablet report...
I20260812 06:17:41.595425  2505 catalog_manager.cc:5719] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 reported cstate change: term changed from 0 to 1, leader changed from <none> to 548094e8e3d94baf82afcb0d1be79157 (127.2.106.65). New cstate: current_term: 1 leader_uuid: "548094e8e3d94baf82afcb0d1be79157" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "548094e8e3d94baf82afcb0d1be79157" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 39469 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:41.661875  2473 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.021s	sys 0.006s
I20260812 06:17:41.793056  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5): perf score=16.078378
I20260812 06:17:41.951099  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.158s	user 0.121s	sys 0.032s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":437,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1096,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36541,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":173312,"thread_start_us":144,"threads_started":1,"update_count":1050}
I20260812 06:17:41.952364  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 20743880 bytes of WAL
I20260812 06:17:41.952677  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 2 log segments from log reader
I20260812 06:17:41.952746  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000001 (ops 1-6)
I20260812 06:17:41.952801  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000002 (ops 7-11)
I20260812 06:17:41.958287  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:41.958721  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5): 16411397 bytes on disk
I20260812 06:17:41.959384  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.959857  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:41.976262  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6270,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.976753  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.102228  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.125s	user 0.090s	sys 0.033s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":579,"lbm_read_time_us":8205,"lbm_reads_lt_1ms":364,"lbm_write_time_us":21784,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":304,"threads_started":5,"update_count":1500}
I20260812 06:17:42.102902  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=7.149875
I20260812 06:17:42.136726  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.034s	user 0.023s	sys 0.008s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":15579,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:17:42.137297  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:42.155704  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.018s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.156241  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.268173  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.112s	user 0.081s	sys 0.030s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569858,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1589,"lbm_read_time_us":7466,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19989,"lbm_writes_lt_1ms":343,"mutex_wait_us":380,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.268772  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:42.309827  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.041s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15599,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.310446  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.416407  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.106s	user 0.082s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1001,"lbm_read_time_us":6526,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20160,"lbm_writes_lt_1ms":343,"mutex_wait_us":319,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":1500}
I20260812 06:17:42.417023  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:42.466526  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.049s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17188,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.467056  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:42.478520  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.479146  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.612797  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.133s	user 0.091s	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":168,"lbm_read_time_us":9828,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24269,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:42.613435  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:42.650102  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.037s	user 0.024s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13598,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.650719  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.782415  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.131s	user 0.093s	sys 0.030s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":2989,"lbm_read_time_us":6127,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19195,"lbm_writes_lt_1ms":343,"mutex_wait_us":2333,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.782971  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:42.819692  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14871,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.820158  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:42.830739  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.831338  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:42.957023  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.125s	user 0.109s	sys 0.016s 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":281,"lbm_read_time_us":7839,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25573,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:17:42.957806  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:43.001622  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.044s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13551,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.002125  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:43.016222  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.016909  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:43.148212  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.131s	user 0.107s	sys 0.024s 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":301,"lbm_read_time_us":9374,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25428,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":112640,"update_count":2000}
I20260812 06:17:43.148900  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:43.195997  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.047s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17138,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.196612  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:43.207433  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.207934  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:43.251149  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.043s	user 0.037s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1633,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2066,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:43.252046  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 112239261 bytes of WAL
I20260812 06:17:43.252295  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 11 log segments from log reader
I20260812 06:17:43.252349  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000003 (ops 12-16)
I20260812 06:17:43.252403  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000004 (ops 17-21)
I20260812 06:17:43.252446  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000005 (ops 22-26)
I20260812 06:17:43.252489  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000006 (ops 27-31)
I20260812 06:17:43.252527  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000007 (ops 32-36)
I20260812 06:17:43.252568  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000008 (ops 37-40)
I20260812 06:17:43.252606  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000009 (ops 41-45)
I20260812 06:17:43.252643  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000010 (ops 46-50)
I20260812 06:17:43.252681  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000011 (ops 51-55)
I20260812 06:17:43.252720  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000012 (ops 56-60)
I20260812 06:17:43.252761  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000013 (ops 61-65)
I20260812 06:17:43.279737  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:43.280189  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=3.181125
I20260812 06:17:43.304473  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.024s	user 0.011s	sys 0.006s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7392,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:43.305009  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5): 448 bytes on disk
I20260812 06:17:43.305445  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:43.306102  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:43.316636  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:43.317124  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:43.512722  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.195s	user 0.154s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2037,"lbm_read_time_us":14007,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31229,"lbm_writes_lt_1ms":643,"mutex_wait_us":1422,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:17:43.513485  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=14.095187
I20260812 06:17:43.558215  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.044s	user 0.018s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20437,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.558920  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:43.714953  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.156s	user 0.112s	sys 0.043s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1001,"lbm_read_time_us":11857,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25287,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:17:43.715543  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:43.761114  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.045s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17381,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.761643  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:43.772672  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.773443  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:43.906608  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.133s	user 0.091s	sys 0.041s 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":1141,"lbm_read_time_us":9094,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26216,"lbm_writes_lt_1ms":443,"mutex_wait_us":424,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:17:43.907199  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:43.956552  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.049s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15914,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.957026  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:43.968210  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4558,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.968714  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:44.099813  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.131s	user 0.100s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":8354,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25875,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:17:44.100553  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:44.139915  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.039s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15023,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.140455  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.156138  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.156819  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:44.288105  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.131s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":8643,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25539,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.288810  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=11.118625
I20260812 06:17:44.332593  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.044s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15866,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:44.333191  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.346473  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5108,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.347211  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:44.500439  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.153s	user 0.085s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1026,"lbm_read_time_us":10578,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26570,"lbm_writes_lt_1ms":443,"mutex_wait_us":296,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:17:44.501143  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=11.118625
I20260812 06:17:44.541491  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17386,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:44.542115  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.552943  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3993,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.553409  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:44.680765  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.127s	user 0.107s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1279,"lbm_read_time_us":8913,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25238,"lbm_writes_lt_1ms":443,"mutex_wait_us":315,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:44.681576  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=10.126437
I20260812 06:17:44.729743  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":23541,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.730494  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.747946  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.748594  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:44.807950  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.059s	user 0.036s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1576,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2220,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:44.808802  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 120553382 bytes of WAL
I20260812 06:17:44.809054  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 12 log segments from log reader
I20260812 06:17:44.809103  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000014 (ops 66-70)
I20260812 06:17:44.809159  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000015 (ops 71-74)
I20260812 06:17:44.809211  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000016 (ops 75-79)
I20260812 06:17:44.809254  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000017 (ops 80-84)
I20260812 06:17:44.809324  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000018 (ops 85-88)
I20260812 06:17:44.809370  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000019 (ops 89-93)
I20260812 06:17:44.809414  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000020 (ops 94-98)
I20260812 06:17:44.809455  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000021 (ops 99-103)
I20260812 06:17:44.809497  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000022 (ops 104-108)
I20260812 06:17:44.809540  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000023 (ops 109-113)
I20260812 06:17:44.809580  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000024 (ops 114-118)
I20260812 06:17:44.809623  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000025 (ops 119-123)
I20260812 06:17:44.838418  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:44.838868  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=6.157687
I20260812 06:17:44.861018  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.022s	user 0.014s	sys 0.005s Metrics: {"bytes_written":8328150,"delete_count":0,"lbm_write_time_us":9183,"lbm_writes_lt_1ms":206,"reinsert_count":0,"update_count":1015}
I20260812 06:17:44.861608  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 12017983 bytes of WAL
I20260812 06:17:44.861840  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 1 log segments from log reader
I20260812 06:17:44.861891  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000026 (ops 124-128)
I20260812 06:17:44.864841  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:44.865326  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5): 482 bytes on disk
I20260812 06:17:44.866045  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":133,"lbm_reads_lt_1ms":4}
I20260812 06:17:44.867154  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.894482  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.027s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5909,"lbm_writes_lt_1ms":100,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":485}
I20260812 06:17:44.895025  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:44.914798  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.020s	user 0.012s	sys 0.007s 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:17:44.915407  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:45.199023  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.283s	user 0.187s	sys 0.085s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":742,"lbm_read_time_us":17486,"lbm_reads_lt_1ms":875,"lbm_write_time_us":48252,"lbm_writes_lt_1ms":843,"mutex_wait_us":53,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":401,"threads_started":6,"update_count":4000}
I20260812 06:17:45.199976  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=18.063937
I20260812 06:17:45.272043  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.072s	user 0.025s	sys 0.036s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28876,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:45.272539  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:45.284511  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.285079  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:45.475025  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.190s	user 0.121s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":417,"lbm_read_time_us":12295,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31266,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":3000}
I20260812 06:17:45.475878  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=14.095187
I20260812 06:17:45.538167  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.062s	user 0.039s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28299,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.538822  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:45.551318  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.551811  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:45.738415  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.186s	user 0.125s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":478,"lbm_read_time_us":11755,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30530,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:45.739095  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=14.095187
I20260812 06:17:45.801457  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.062s	user 0.026s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22463,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.802073  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:45.814428  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.815011  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:45.998600  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.183s	user 0.140s	sys 0.038s 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":759,"lbm_read_time_us":13901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31075,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:45.999714  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=11.118625
I20260812 06:17:46.054826  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.055s	user 0.035s	sys 0.016s Metrics: {"bytes_written":13127976,"delete_count":0,"lbm_write_time_us":17948,"lbm_writes_lt_1ms":323,"reinsert_count":0,"update_count":1600}
I20260812 06:17:46.055968  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=4.173312
I20260812 06:17:46.074168  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.018s	user 0.000s	sys 0.016s Metrics: {"bytes_written":5456466,"delete_count":0,"lbm_write_time_us":7725,"lbm_writes_lt_1ms":136,"reinsert_count":0,"update_count":665}
I20260812 06:17:46.074693  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:46.080865  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":1927,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:17:46.081391  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:46.274641  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.193s	user 0.124s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774764,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2986,"lbm_read_time_us":12785,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32347,"lbm_writes_lt_1ms":543,"mutex_wait_us":2647,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29184,"update_count":2500}
I20260812 06:17:46.275499  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=11.118625
I20260812 06:17:46.318724  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.043s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16094,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:46.319398  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:46.339356  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.020s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.339973  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:46.351585  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.352241  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:46.396586  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushMRSOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.044s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1739,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:46.397300  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 112692632 bytes of WAL
I20260812 06:17:46.397542  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 11 log segments from log reader
I20260812 06:17:46.397588  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000027 (ops 129-133)
I20260812 06:17:46.397617  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000028 (ops 134-138)
I20260812 06:17:46.397687  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000029 (ops 139-143)
I20260812 06:17:46.397742  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000030 (ops 144-148)
I20260812 06:17:46.397780  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000031 (ops 149-153)
I20260812 06:17:46.397804  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000032 (ops 154-158)
I20260812 06:17:46.397867  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000033 (ops 159-163)
I20260812 06:17:46.397907  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000034 (ops 164-168)
I20260812 06:17:46.397944  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000035 (ops 169-173)
I20260812 06:17:46.397981  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000036 (ops 174-178)
I20260812 06:17:46.398017  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000037 (ops 179-183)
I20260812 06:17:46.420885  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:46.421373  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:46.440745  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.019s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5909,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.441223  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling LogGCOp(ff6889db132c4d14bd89f930ca1736f5): free 12017954 bytes of WAL
I20260812 06:17:46.441439  2580 log_reader.cc:385] T ff6889db132c4d14bd89f930ca1736f5: removed 1 log segments from log reader
I20260812 06:17:46.441483  2580 log.cc:1079] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/ff6889db132c4d14bd89f930ca1736f5/wal-000000038 (ops 184-188)
I20260812 06:17:46.443789  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: LogGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:46.444110  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5): 463 bytes on disk
I20260812 06:17:46.444527  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: UndoDeltaBlockGCOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:46.445047  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:46.457322  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.457863  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:46.697106  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.239s	user 0.159s	sys 0.063s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1314,"lbm_read_time_us":16574,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39961,"lbm_writes_lt_1ms":743,"mutex_wait_us":334,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16256,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:17:46.697888  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=18.063937
I20260812 06:17:46.751883  2473 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.090s	user 1.882s	sys 0.137s
I20260812 06:17:46.757747  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.060s	user 0.039s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27126,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:46.758455  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5): perf score=2.188937
I20260812 06:17:46.775578  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: FlushDeltaMemStoresOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6547,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":500}
I20260812 06:17:46.776266  2649 maintenance_manager.cc:419] P 548094e8e3d94baf82afcb0d1be79157: Scheduling MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5): perf score=1.000000
I20260812 06:17:46.850638  2473 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.003s	sys 0.000s
I20260812 06:17:46.851298  2473 tablet_server.cc:179] TabletServer@127.2.106.65:0 shutting down...
I20260812 06:17:46.950847  2580 maintenance_manager.cc:643] P 548094e8e3d94baf82afcb0d1be79157: MajorDeltaCompactionOp(ff6889db132c4d14bd89f930ca1736f5) complete. Timing: real 0.174s	user 0.135s	sys 0.039s Metrics: {"cfile_cache_hit":308,"cfile_cache_hit_bytes":12597058,"cfile_cache_miss":324,"cfile_cache_miss_bytes":16280043,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":750,"lbm_read_time_us":10128,"lbm_reads_lt_1ms":356,"lbm_write_time_us":30189,"lbm_writes_lt_1ms":643,"mutex_wait_us":135,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":86528,"update_count":3000}
I20260812 06:17:46.951678  2473 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:46.952111  2473 tablet_replica.cc:333] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157: stopping tablet replica
I20260812 06:17:46.952425  2473 raft_consensus.cc:2243] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:46.952720  2473 raft_consensus.cc:2272] T ff6889db132c4d14bd89f930ca1736f5 P 548094e8e3d94baf82afcb0d1be79157 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:46.969686  2473 tablet_server.cc:196] TabletServer@127.2.106.65:0 shutdown complete.
I20260812 06:17:47.006667  2473 master.cc:562] Master@127.2.106.126:46077 shutting down...
I20260812 06:17:47.012655  2473 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:47.012952  2473 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:47.013057  2473 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3c5664786e6e444faf2908427c58c56f: stopping tablet replica
I20260812 06:17:47.025848  2473 master.cc:584] Master@127.2.106.126:46077 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5710 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:47.113893  2473 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.106.126:35973
I20260812 06:17:47.114310  2473 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:47.117390  2688 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:17:47.117439  2685 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:17:47.117520  2473 server_base.cc:1061] running on GCE node
W20260812 06:17:47.117477  2686 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:17:47.117909  2473 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.117956  2473 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:17:47.117972  2473 hybrid_clock.cc:648] HybridClock initialized: now 1786515467117972 us; error 0 us; skew 500 ppm
I20260812 06:17:47.119004  2473 webserver.cc:533] Webserver started at http://127.2.106.126:35997/ using document root <none> and password file <none>
I20260812 06:17:47.119177  2473 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.119225  2473 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.119278  2473 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.119625  2473 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/master-0-root/instance:
uuid: "0a3b9c9bc451464a9dca5bd6a76898d6"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-zpfg"
I20260812 06:17:47.121145  2473 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:47.122139  2693 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:17:47.122449  2473 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:47.122519  2473 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/master-0-root
uuid: "0a3b9c9bc451464a9dca5bd6a76898d6"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-zpfg"
I20260812 06:17:47.122617  2473 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-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:17:47.133941  2473 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.134454  2473 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.138985  2473 rpc_server.cc:307] RPC server started. Bound to: 127.2.106.126:35973
I20260812 06:17:47.141227  2749 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.106.126:35973 every 8 connection(s)
I20260812 06:17:47.145275  2750 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:17:47.148221  2750 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6: Bootstrap starting.
I20260812 06:17:47.149044  2750 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.150116  2750 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6: No bootstrap required, opened a new log
I20260812 06:17:47.150612  2750 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER }
I20260812 06:17:47.150702  2750 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.150761  2750 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0a3b9c9bc451464a9dca5bd6a76898d6, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.150959  2750 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [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: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER }
I20260812 06:17:47.151036  2750 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.151095  2750 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.151156  2750 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.151885  2750 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER }
I20260812 06:17:47.152037  2750 leader_election.cc:304] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [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: 0a3b9c9bc451464a9dca5bd6a76898d6; no voters: 
I20260812 06:17:47.152257  2750 leader_election.cc:290] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.152426  2753 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.152643  2753 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 1 LEADER]: Becoming Leader. State: Replica: 0a3b9c9bc451464a9dca5bd6a76898d6, State: Running, Role: LEADER
I20260812 06:17:47.152752  2750 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:47.152825  2753 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [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: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER }
I20260812 06:17:47.153281  2755 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0a3b9c9bc451464a9dca5bd6a76898d6. Latest consensus state: current_term: 1 leader_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER } }
I20260812 06:17:47.153258  2754 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0a3b9c9bc451464a9dca5bd6a76898d6" member_type: VOTER } }
I20260812 06:17:47.153370  2755 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.153380  2754 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.153749  2759 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:47.154613  2759 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:47.154831  2473 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:47.156569  2759 catalog_manager.cc:1383] Generated new cluster ID: 53066d3e7ba442ca8a5d06f2d7f3bbd3
I20260812 06:17:47.156630  2759 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:47.170583  2759 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:47.171192  2759 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:47.194284  2759 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6: Generated new TSK 0
I20260812 06:17:47.194553  2759 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:47.219736  2473 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:47.222399  2775 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:17:47.222507  2773 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:17:47.222368  2772 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:17:47.222534  2473 server_base.cc:1061] running on GCE node
I20260812 06:17:47.222888  2473 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.222929  2473 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:17:47.222946  2473 hybrid_clock.cc:648] HybridClock initialized: now 1786515467222946 us; error 0 us; skew 500 ppm
I20260812 06:17:47.223850  2473 webserver.cc:533] Webserver started at http://127.2.106.65:42401/ using document root <none> and password file <none>
I20260812 06:17:47.223996  2473 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.224040  2473 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.224092  2473 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.224457  2473 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/instance:
uuid: "ff24cc582dab4c528f893ad0c090ea23"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-zpfg"
I20260812 06:17:47.226090  2473 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:47.227396  2781 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:17:47.227725  2473 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:47.227797  2473 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root
uuid: "ff24cc582dab4c528f893ad0c090ea23"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-zpfg"
I20260812 06:17:47.227890  2473 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-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:17:47.255771  2473 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.256201  2473 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.256613  2473 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:47.257176  2473 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:47.257241  2473 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.257308  2473 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:47.257349  2473 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.261730  2473 rpc_server.cc:307] RPC server started. Bound to: 127.2.106.65:33247
I20260812 06:17:47.264026  2848 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.106.65:33247 every 8 connection(s)
I20260812 06:17:47.280884  2849 heartbeater.cc:344] Connected to a master server at 127.2.106.126:35973
I20260812 06:17:47.281055  2849 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:47.281325  2849 heartbeater.cc:507] Master 127.2.106.126:35973 requested a full tablet report, sending...
I20260812 06:17:47.282101  2711 ts_manager.cc:194] Registered new tserver with Master: ff24cc582dab4c528f893ad0c090ea23 (127.2.106.65:33247)
I20260812 06:17:47.282655  2473 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020184665s
I20260812 06:17:47.282997  2711 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34342
I20260812 06:17:47.291316  2711 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34344:
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:17:47.301352  2811 tablet_service.cc:1511] Processing CreateTablet for tablet 50a7bd7101764fb0a82ff5d47bb5bada (DEFAULT_TABLE table=heavy-update-compaction-test [id=8df172add2894d48ae04cb026ad6c05a]), partition=
I20260812 06:17:47.301777  2811 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 50a7bd7101764fb0a82ff5d47bb5bada. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:47.304319  2861 tablet_bootstrap.cc:492] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Bootstrap starting.
I20260812 06:17:47.305225  2861 tablet_bootstrap.cc:654] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.306288  2861 tablet_bootstrap.cc:492] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: No bootstrap required, opened a new log
I20260812 06:17:47.306450  2861 ts_tablet_manager.cc:1403] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:17:47.306938  2861 raft_consensus.cc:359] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff24cc582dab4c528f893ad0c090ea23" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 33247 } }
I20260812 06:17:47.307027  2861 raft_consensus.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.307050  2861 raft_consensus.cc:740] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ff24cc582dab4c528f893ad0c090ea23, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.307232  2861 consensus_queue.cc:260] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [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: "ff24cc582dab4c528f893ad0c090ea23" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 33247 } }
I20260812 06:17:47.307325  2861 raft_consensus.cc:399] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.307380  2861 raft_consensus.cc:493] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.307438  2861 raft_consensus.cc:3060] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.308154  2861 raft_consensus.cc:515] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff24cc582dab4c528f893ad0c090ea23" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 33247 } }
I20260812 06:17:47.308275  2861 leader_election.cc:304] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [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: ff24cc582dab4c528f893ad0c090ea23; no voters: 
I20260812 06:17:47.308528  2861 leader_election.cc:290] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.308709  2863 raft_consensus.cc:2804] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.308843  2861 ts_tablet_manager.cc:1434] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:47.308879  2849 heartbeater.cc:499] Master 127.2.106.126:35973 was elected leader, sending a full tablet report...
I20260812 06:17:47.308848  2863 raft_consensus.cc:697] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 1 LEADER]: Becoming Leader. State: Replica: ff24cc582dab4c528f893ad0c090ea23, State: Running, Role: LEADER
I20260812 06:17:47.309031  2863 consensus_queue.cc:237] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [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: "ff24cc582dab4c528f893ad0c090ea23" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 33247 } }
I20260812 06:17:47.310578  2711 catalog_manager.cc:5719] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 reported cstate change: term changed from 0 to 1, leader changed from <none> to ff24cc582dab4c528f893ad0c090ea23 (127.2.106.65). New cstate: current_term: 1 leader_uuid: "ff24cc582dab4c528f893ad0c090ea23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff24cc582dab4c528f893ad0c090ea23" member_type: VOTER last_known_addr { host: "127.2.106.65" port: 33247 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:47.372074  2473 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.011s	sys 0.012s
I20260812 06:17:47.514606  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=19.054940
I20260812 06:17:47.664572  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.150s	user 0.098s	sys 0.049s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1021,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38089,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:47.665283  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 20743880 bytes of WAL
I20260812 06:17:47.665547  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 2 log segments from log reader
I20260812 06:17:47.665619  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000001 (ops 1-6)
I20260812 06:17:47.665675  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000002 (ops 7-11)
I20260812 06:17:47.670156  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:47.670713  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:47.686681  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.687121  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada): 16411395 bytes on disk
I20260812 06:17:47.687599  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.688037  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:47.836484  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.148s	user 0.127s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":324,"lbm_read_time_us":9833,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25411,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":317,"threads_started":5,"update_count":2000}
I20260812 06:17:47.837116  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=11.118625
I20260812 06:17:47.879500  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.042s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18779,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:47.880038  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:47.893579  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:47.894229  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:48.078557  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.184s	user 0.138s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":346,"lbm_read_time_us":10644,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29371,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:17:48.079317  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=11.118625
I20260812 06:17:48.128065  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20622,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.128607  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:48.147732  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.019s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.148242  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:48.158083  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3654,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.158569  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:48.338518  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.180s	user 0.125s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":393,"lbm_read_time_us":10937,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28190,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:17:48.339094  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:48.395666  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.056s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27523,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.396157  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:48.407704  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.410423  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:48.567075  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.156s	user 0.114s	sys 0.041s 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":589,"lbm_read_time_us":9906,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29320,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:48.567802  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=11.118625
I20260812 06:17:48.607923  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.040s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16662,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.608958  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:48.622222  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5065,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.622767  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:48.752624  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.130s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":411,"lbm_read_time_us":8994,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24292,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:17:48.753309  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=10.126437
I20260812 06:17:48.798910  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.045s	user 0.041s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17508,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.799533  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:48.812021  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.812572  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:48.941664  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.129s	user 0.097s	sys 0.032s 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":249,"lbm_read_time_us":8051,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24600,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:17:48.942505  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=10.126437
I20260812 06:17:48.990563  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.048s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13923,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.991284  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.007927  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.008553  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:49.059710  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.051s	user 0.033s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2109,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:49.060411  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 120553376 bytes of WAL
I20260812 06:17:49.060654  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 12 log segments from log reader
I20260812 06:17:49.060702  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000003 (ops 12-16)
I20260812 06:17:49.060756  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000004 (ops 17-21)
I20260812 06:17:49.060807  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000005 (ops 22-26)
I20260812 06:17:49.060849  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000006 (ops 27-30)
I20260812 06:17:49.060890  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000007 (ops 31-35)
I20260812 06:17:49.060932  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000008 (ops 36-40)
I20260812 06:17:49.060971  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000009 (ops 41-45)
I20260812 06:17:49.061038  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000010 (ops 46-50)
I20260812 06:17:49.061075  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000011 (ops 51-55)
I20260812 06:17:49.061117  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000012 (ops 56-60)
I20260812 06:17:49.061158  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000013 (ops 61-64)
I20260812 06:17:49.061198  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000014 (ops 65-69)
I20260812 06:17:49.085752  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:49.086189  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.109850  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.023s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.110303  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada): 471 bytes on disk
I20260812 06:17:49.110765  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:49.111272  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.121958  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.122628  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:49.330092  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.207s	user 0.149s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":602,"lbm_read_time_us":14282,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33537,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:17:49.330909  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:49.397663  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.067s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.398142  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.408496  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.408980  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:49.595906  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.187s	user 0.128s	sys 0.058s 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":262,"lbm_read_time_us":12466,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32591,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":86144,"update_count":2500}
I20260812 06:17:49.596540  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:49.653959  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.057s	user 0.038s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.654604  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.667661  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.668159  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:49.843796  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.175s	user 0.113s	sys 0.063s 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":200,"lbm_read_time_us":11889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29197,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:17:49.844565  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:49.902606  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.058s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21529,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.903199  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.931752  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.028s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.932276  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:49.943187  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.943740  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:50.170106  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.226s	user 0.151s	sys 0.065s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":237,"lbm_read_time_us":12888,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34365,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":3000}
I20260812 06:17:50.170907  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=18.063937
I20260812 06:17:50.249915  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.079s	user 0.039s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29922,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:50.250600  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:50.264786  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.265414  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:50.500763  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.235s	user 0.149s	sys 0.079s 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":825,"lbm_read_time_us":17146,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36757,"lbm_writes_lt_1ms":643,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":3000}
I20260812 06:17:50.501497  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=18.063937
I20260812 06:17:50.573956  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.072s	user 0.035s	sys 0.024s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":28537,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:50.574532  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:50.586371  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.586966  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:50.620700  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1433,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1462,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:50.621367  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 120553329 bytes of WAL
I20260812 06:17:50.621601  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 12 log segments from log reader
I20260812 06:17:50.621662  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000015 (ops 70-74)
I20260812 06:17:50.621712  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000016 (ops 75-79)
I20260812 06:17:50.621767  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000017 (ops 80-84)
I20260812 06:17:50.621811  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000018 (ops 85-88)
I20260812 06:17:50.621858  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000019 (ops 89-93)
I20260812 06:17:50.621897  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000020 (ops 94-98)
I20260812 06:17:50.621935  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000021 (ops 99-103)
I20260812 06:17:50.621973  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000022 (ops 104-108)
I20260812 06:17:50.622012  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000023 (ops 109-113)
I20260812 06:17:50.622051  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000024 (ops 114-118)
I20260812 06:17:50.622089  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000025 (ops 119-122)
I20260812 06:17:50.622128  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000026 (ops 123-127)
I20260812 06:17:50.648635  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:50.649065  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=3.181125
I20260812 06:17:50.662747  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4722,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:50.663260  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 12018000 bytes of WAL
I20260812 06:17:50.663517  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 1 log segments from log reader
I20260812 06:17:50.663583  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000027 (ops 128-132)
I20260812 06:17:50.665886  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:50.666229  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:50.678650  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.679206  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:50.938134  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.259s	user 0.178s	sys 0.075s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082160,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":949,"lbm_read_time_us":19582,"lbm_reads_lt_1ms":874,"lbm_write_time_us":46678,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:17:50.938987  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=19.056125
I20260812 06:17:51.011510  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.072s	user 0.043s	sys 0.027s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":31774,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":512,"reinsert_count":0,"update_count":2550}
I20260812 06:17:51.012156  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada): 473 bytes on disk
I20260812 06:17:51.012633  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.013211  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=6.157687
I20260812 06:17:51.051692  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.038s	user 0.009s	sys 0.016s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11689,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:51.052174  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:51.065214  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.065783  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:51.275125  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.209s	user 0.173s	sys 0.035s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082042,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":330,"lbm_read_time_us":15810,"lbm_reads_lt_1ms":873,"lbm_write_time_us":43450,"lbm_writes_lt_1ms":843,"mutex_wait_us":59,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":4000}
I20260812 06:17:51.275790  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=18.063937
I20260812 06:17:51.346134  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.070s	user 0.037s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":29196,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:51.346855  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:51.371551  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.025s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.372102  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:51.382875  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.383358  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:51.572582  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.189s	user 0.153s	sys 0.036s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":873,"lbm_read_time_us":14022,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39036,"lbm_writes_lt_1ms":743,"mutex_wait_us":35,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":3500}
I20260812 06:17:51.573424  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:51.618963  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.045s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19708,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.619618  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:51.633250  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.633811  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:51.792150  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.158s	user 0.120s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":690,"lbm_read_time_us":11333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28446,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:17:51.792863  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:51.852725  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.060s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22572,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.853266  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=2.188937
I20260812 06:17:51.864212  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.865053  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:52.050864  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.186s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":984,"lbm_read_time_us":11409,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32894,"lbm_writes_lt_1ms":543,"mutex_wait_us":404,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:52.051643  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=14.095187
I20260812 06:17:52.098436  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.044s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20081,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.098939  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:52.135739  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushMRSOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.037s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1446,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1637,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:52.136510  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 117302827 bytes of WAL
I20260812 06:17:52.136787  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 12 log segments from log reader
I20260812 06:17:52.136857  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000028 (ops 133-137)
I20260812 06:17:52.136890  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000029 (ops 138-142)
I20260812 06:17:52.136950  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000030 (ops 143-146)
I20260812 06:17:52.136992  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000031 (ops 147-151)
I20260812 06:17:52.137027  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000032 (ops 152-156)
I20260812 06:17:52.137068  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000033 (ops 157-160)
I20260812 06:17:52.137120  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000034 (ops 161-165)
I20260812 06:17:52.137158  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000035 (ops 166-170)
I20260812 06:17:52.137182  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000036 (ops 171-175)
I20260812 06:17:52.137241  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000037 (ops 176-180)
I20260812 06:17:52.137283  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000038 (ops 181-185)
I20260812 06:17:52.137312  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000039 (ops 186-190)
I20260812 06:17:52.165753  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:52.166272  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=6.157687
I20260812 06:17:52.188349  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.022s	user 0.014s	sys 0.006s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":8795,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:17:52.188853  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada): free 12017949 bytes of WAL
I20260812 06:17:52.189075  2787 log_reader.cc:385] T 50a7bd7101764fb0a82ff5d47bb5bada: removed 1 log segments from log reader
I20260812 06:17:52.189136  2787 log.cc:1079] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: Deleting log segment in path: /tmp/dist-test-taskbushB8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515461392481-2473-0/minicluster-data/ts-0-root/wals/50a7bd7101764fb0a82ff5d47bb5bada/wal-000000040 (ops 191-195)
I20260812 06:17:52.192109  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: LogGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:52.192487  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada): 492 bytes on disk
I20260812 06:17:52.192893  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: UndoDeltaBlockGCOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:52.193392  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=1.000000
I20260812 06:17:52.322089  2473 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.950s	user 1.856s	sys 0.172s
I20260812 06:17:52.385358  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: MajorDeltaCompactionOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.192s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":624,"cfile_cache_miss_bytes":28548910,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":12586,"lbm_reads_lt_1ms":652,"lbm_write_time_us":34037,"lbm_writes_lt_1ms":635,"mutex_wait_us":52,"peak_mem_usage":74173808,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":93,"threads_started":1,"update_count":2960}
I20260812 06:17:52.386138  2850 maintenance_manager.cc:419] P ff24cc582dab4c528f893ad0c090ea23: Scheduling FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada): perf score=11.118625
I20260812 06:17:52.398792  2473 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.003s	sys 0.000s
I20260812 06:17:52.399324  2473 tablet_server.cc:179] TabletServer@127.2.106.65:0 shutting down...
I20260812 06:17:52.420881  2787 maintenance_manager.cc:643] P ff24cc582dab4c528f893ad0c090ea23: FlushDeltaMemStoresOp(50a7bd7101764fb0a82ff5d47bb5bada) complete. Timing: real 0.034s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12635687,"delete_count":0,"lbm_write_time_us":15064,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:17:52.421693  2473 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:52.422021  2473 tablet_replica.cc:333] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23: stopping tablet replica
I20260812 06:17:52.422168  2473 raft_consensus.cc:2243] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:52.422397  2473 raft_consensus.cc:2272] T 50a7bd7101764fb0a82ff5d47bb5bada P ff24cc582dab4c528f893ad0c090ea23 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:52.436239  2473 tablet_server.cc:196] TabletServer@127.2.106.65:0 shutdown complete.
I20260812 06:17:52.439399  2473 master.cc:562] Master@127.2.106.126:35973 shutting down...
I20260812 06:17:52.442744  2473 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:52.442937  2473 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:52.442991  2473 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0a3b9c9bc451464a9dca5bd6a76898d6: stopping tablet replica
I20260812 06:17:52.455384  2473 master.cc:584] Master@127.2.106.126:35973 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5424 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11136 ms total)

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