[==========] 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:31.367358  7435 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.66.254:46111
I20260812 06:17:31.368566  7435 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:31.369234  7435 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.376063  7445 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:31.376128  7435 server_base.cc:1061] running on GCE node
W20260812 06:17:31.376286  7448 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:31.376138  7443 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:31.376929  7435 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.377096  7435 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:31.377147  7435 hybrid_clock.cc:648] HybridClock initialized: now 1786515451377145 us; error 0 us; skew 500 ppm
I20260812 06:17:31.379031  7435 webserver.cc:533] Webserver started at http://127.7.66.254:42761/ using document root <none> and password file <none>
I20260812 06:17:31.379700  7435 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.379822  7435 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.380100  7435 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.381844  7435 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/master-0-root/instance:
uuid: "8e9ac39ebca841df819069f048f061d7"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-7f01"
I20260812 06:17:31.385762  7435 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:17:31.387997  7455 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:31.389585  7435 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:31.389739  7435 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/master-0-root
uuid: "8e9ac39ebca841df819069f048f061d7"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-7f01"
I20260812 06:17:31.389855  7435 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-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:31.402547  7435 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.403196  7435 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:31.403384  7435 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.411923  7435 rpc_server.cc:307] RPC server started. Bound to: 127.7.66.254:46111
I20260812 06:17:31.411966  7550 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.66.254:46111 every 8 connection(s)
I20260812 06:17:31.414402  7551 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:31.420097  7551 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: Bootstrap starting.
I20260812 06:17:31.422618  7551 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.423601  7551 log.cc:826] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:31.425422  7551 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: No bootstrap required, opened a new log
I20260812 06:17:31.428524  7551 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER }
I20260812 06:17:31.428691  7551 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.428766  7551 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8e9ac39ebca841df819069f048f061d7, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.429400  7551 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [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: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER }
I20260812 06:17:31.429566  7551 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.429666  7551 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.429819  7551 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.430647  7551 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER }
I20260812 06:17:31.431110  7551 leader_election.cc:304] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [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: 8e9ac39ebca841df819069f048f061d7; no voters: 
I20260812 06:17:31.431450  7551 leader_election.cc:290] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.431599  7561 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.431876  7561 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 1 LEADER]: Becoming Leader. State: Replica: 8e9ac39ebca841df819069f048f061d7, State: Running, Role: LEADER
I20260812 06:17:31.432307  7561 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [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: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER }
I20260812 06:17:31.432613  7551 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:31.434171  7567 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8e9ac39ebca841df819069f048f061d7. Latest consensus state: current_term: 1 leader_uuid: "8e9ac39ebca841df819069f048f061d7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER } }
I20260812 06:17:31.434299  7567 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.434418  7563 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8e9ac39ebca841df819069f048f061d7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8e9ac39ebca841df819069f048f061d7" member_type: VOTER } }
I20260812 06:17:31.434517  7563 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.435322  7435 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:31.437412  7588 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:31.437479  7588 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:31.437537  7578 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:31.438303  7578 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:31.443409  7578 catalog_manager.cc:1383] Generated new cluster ID: 841e296155fd4eb7a39cb91299993d93
I20260812 06:17:31.443486  7578 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.497363  7578 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.498349  7578 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.509539  7578 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: Generated new TSK 0
I20260812 06:17:31.510560  7578 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.564643  7435 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.567663  7595 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:31.567698  7604 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:31.567963  7435 server_base.cc:1061] running on GCE node
W20260812 06:17:31.567796  7597 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:31.568363  7435 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.568423  7435 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:31.568449  7435 hybrid_clock.cc:648] HybridClock initialized: now 1786515451568447 us; error 0 us; skew 500 ppm
I20260812 06:17:31.569514  7435 webserver.cc:533] Webserver started at http://127.7.66.193:39645/ using document root <none> and password file <none>
I20260812 06:17:31.569700  7435 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.569774  7435 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.569857  7435 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.570278  7435 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/instance:
uuid: "9be222b6031d42a0a2a6477a69ba1a90"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-7f01"
I20260812 06:17:31.571887  7435 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:31.572948  7619 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:31.573207  7435 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:31.573311  7435 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root
uuid: "9be222b6031d42a0a2a6477a69ba1a90"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-7f01"
I20260812 06:17:31.573411  7435 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-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:31.588534  7435 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.589035  7435 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.589573  7435 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:31.590561  7435 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:31.590667  7435 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.590746  7435 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:31.590798  7435 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.597549  7435 rpc_server.cc:307] RPC server started. Bound to: 127.7.66.193:45841
I20260812 06:17:31.597776  7724 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.66.193:45841 every 8 connection(s)
I20260812 06:17:31.607574  7727 heartbeater.cc:344] Connected to a master server at 127.7.66.254:46111
I20260812 06:17:31.607895  7727 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:31.608449  7727 heartbeater.cc:507] Master 127.7.66.254:46111 requested a full tablet report, sending...
I20260812 06:17:31.610013  7484 ts_manager.cc:194] Registered new tserver with Master: 9be222b6031d42a0a2a6477a69ba1a90 (127.7.66.193:45841)
I20260812 06:17:31.610692  7435 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012387814s
I20260812 06:17:31.611465  7484 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50352
I20260812 06:17:31.620487  7484 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50354:
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:31.633653  7663 tablet_service.cc:1511] Processing CreateTablet for tablet 50de5e78a3b6432088f8b5b5ff124376 (DEFAULT_TABLE table=heavy-update-compaction-test [id=69ab15e4d1fe4dc78eb2ed48ed400b5a]), partition=
I20260812 06:17:31.634187  7663 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 50de5e78a3b6432088f8b5b5ff124376. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.645152  7752 tablet_bootstrap.cc:492] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Bootstrap starting.
I20260812 06:17:31.646116  7752 tablet_bootstrap.cc:654] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.647363  7752 tablet_bootstrap.cc:492] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: No bootstrap required, opened a new log
I20260812 06:17:31.647491  7752 ts_tablet_manager.cc:1403] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:31.647929  7752 raft_consensus.cc:359] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9be222b6031d42a0a2a6477a69ba1a90" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 45841 } }
I20260812 06:17:31.648059  7752 raft_consensus.cc:385] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.648108  7752 raft_consensus.cc:740] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9be222b6031d42a0a2a6477a69ba1a90, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.648252  7752 consensus_queue.cc:260] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [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: "9be222b6031d42a0a2a6477a69ba1a90" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 45841 } }
I20260812 06:17:31.648360  7752 raft_consensus.cc:399] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.648408  7752 raft_consensus.cc:493] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.648463  7752 raft_consensus.cc:3060] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.649163  7752 raft_consensus.cc:515] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9be222b6031d42a0a2a6477a69ba1a90" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 45841 } }
I20260812 06:17:31.649325  7752 leader_election.cc:304] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [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: 9be222b6031d42a0a2a6477a69ba1a90; no voters: 
I20260812 06:17:31.649545  7752 leader_election.cc:290] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.649732  7756 raft_consensus.cc:2804] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.649955  7752 ts_tablet_manager.cc:1434] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:31.650022  7756 raft_consensus.cc:697] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 1 LEADER]: Becoming Leader. State: Replica: 9be222b6031d42a0a2a6477a69ba1a90, State: Running, Role: LEADER
I20260812 06:17:31.650215  7727 heartbeater.cc:499] Master 127.7.66.254:46111 was elected leader, sending a full tablet report...
I20260812 06:17:31.650213  7756 consensus_queue.cc:237] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [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: "9be222b6031d42a0a2a6477a69ba1a90" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 45841 } }
I20260812 06:17:31.653077  7483 catalog_manager.cc:5719] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9be222b6031d42a0a2a6477a69ba1a90 (127.7.66.193). New cstate: current_term: 1 leader_uuid: "9be222b6031d42a0a2a6477a69ba1a90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9be222b6031d42a0a2a6477a69ba1a90" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 45841 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:31.718479  7435 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.022s	sys 0.004s
I20260812 06:17:31.848907  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376): perf score=15.086190
I20260812 06:17:32.002869  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.154s	user 0.130s	sys 0.020s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":216,"delete_count":0,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":787,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39756,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":110,"threads_started":1,"update_count":1450}
I20260812 06:17:32.003983  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376): 12719216 bytes on disk
I20260812 06:17:32.004509  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376) 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:32.005012  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:32.130214  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.125s	user 0.094s	sys 0.020s Metrics: {"cfile_cache_miss":321,"cfile_cache_miss_bytes":16159505,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":647,"lbm_read_time_us":6691,"lbm_reads_lt_1ms":349,"lbm_write_time_us":21060,"lbm_writes_lt_1ms":333,"peak_mem_usage":36812022,"reinsert_count":0,"thread_start_us":309,"threads_started":5,"update_count":1450}
I20260812 06:17:32.130810  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling LogGCOp(50de5e78a3b6432088f8b5b5ff124376): free 20743880 bytes of WAL
I20260812 06:17:32.131161  7626 log_reader.cc:385] T 50de5e78a3b6432088f8b5b5ff124376: removed 2 log segments from log reader
I20260812 06:17:32.131248  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000001 (ops 1-6)
I20260812 06:17:32.131320  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000002 (ops 7-11)
I20260812 06:17:32.136526  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: LogGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:32.136953  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:32.176962  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.040s	user 0.025s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15820,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.177443  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:32.188833  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.189904  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:32.313282  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.123s	user 0.085s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":445,"lbm_read_time_us":8751,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23825,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.313999  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:32.367256  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.053s	user 0.024s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17729,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.367978  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:32.379711  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.380264  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:32.528446  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.148s	user 0.092s	sys 0.054s 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":143,"lbm_read_time_us":11785,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22676,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:17:32.529301  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:32.579193  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.579838  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:32.591374  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.592119  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:32.720513  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.128s	user 0.115s	sys 0.012s 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":244,"lbm_read_time_us":8209,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25605,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:17:32.721163  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:32.768352  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.047s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18792,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.768967  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:32.780705  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.781307  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:32.914742  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.133s	user 0.118s	sys 0.015s 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":1232,"lbm_read_time_us":10536,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25337,"lbm_writes_lt_1ms":443,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:17:32.915412  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:32.972055  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.056s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15492,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.972630  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:32.984320  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.984845  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:33.135145  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.150s	user 0.099s	sys 0.049s 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":380,"lbm_read_time_us":12014,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25010,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.135686  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:33.182516  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.047s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16589,"lbm_writes_lt_1ms":303,"mutex_wait_us":1,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.183084  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:33.195986  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.196739  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:33.331164  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.134s	user 0.106s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1076,"lbm_read_time_us":9123,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25549,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:33.331874  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:33.378876  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.047s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16293,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.379421  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:33.391011  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.391645  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:33.422060  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1379,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1696,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:33.423056  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling LogGCOp(50de5e78a3b6432088f8b5b5ff124376): free 124257244 bytes of WAL
I20260812 06:17:33.423326  7626 log_reader.cc:385] T 50de5e78a3b6432088f8b5b5ff124376: removed 12 log segments from log reader
I20260812 06:17:33.423395  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000003 (ops 12-16)
I20260812 06:17:33.423444  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000004 (ops 17-21)
I20260812 06:17:33.423506  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000005 (ops 22-26)
I20260812 06:17:33.423552  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000006 (ops 27-31)
I20260812 06:17:33.423591  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000007 (ops 32-36)
I20260812 06:17:33.423630  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000008 (ops 37-40)
I20260812 06:17:33.423668  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000009 (ops 41-45)
I20260812 06:17:33.423708  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000010 (ops 46-50)
I20260812 06:17:33.423766  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000011 (ops 51-55)
I20260812 06:17:33.423802  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000012 (ops 56-60)
I20260812 06:17:33.423836  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000013 (ops 61-65)
I20260812 06:17:33.423873  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000014 (ops 66-70)
I20260812 06:17:33.452594  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: LogGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:33.453078  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376): 472 bytes on disk
I20260812 06:17:33.453639  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.454108  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=3.181125
I20260812 06:17:33.466985  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.013s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5026,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.467403  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:33.479494  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4781,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.479970  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:33.672333  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.192s	user 0.141s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1615,"lbm_read_time_us":13765,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37442,"lbm_writes_lt_1ms":643,"mutex_wait_us":1033,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:33.673017  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:33.736639  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.063s	user 0.037s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25726,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.737185  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:33.752853  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6021,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.753607  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:33.904100  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.150s	user 0.114s	sys 0.036s 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":467,"lbm_read_time_us":9560,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28800,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:33.907362  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=11.118625
I20260812 06:17:33.949046  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.041s	user 0.028s	sys 0.012s Metrics: {"bytes_written":13168992,"delete_count":0,"lbm_write_time_us":17749,"lbm_writes_lt_1ms":324,"reinsert_count":0,"update_count":1605}
I20260812 06:17:33.949568  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:33.959868  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":3469,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:33.960471  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:34.119057  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.158s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672250,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":10260,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26648,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:34.119685  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:34.177487  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.058s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.178097  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.193760  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.194418  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:34.364964  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.170s	user 0.119s	sys 0.049s 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":233,"lbm_read_time_us":13598,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29443,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.365676  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=11.118625
I20260812 06:17:34.402616  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.037s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16388,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.403148  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.422514  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5203,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.423166  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:34.544358  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.121s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":128,"lbm_read_time_us":7834,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23743,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:34.544998  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:34.584492  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.039s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17700,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.585028  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.596058  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.596896  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:34.726652  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.130s	user 0.109s	sys 0.020s 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":1284,"lbm_read_time_us":8722,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23972,"lbm_writes_lt_1ms":443,"mutex_wait_us":405,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:17:34.727557  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:34.769335  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.042s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16142,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.769870  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.780957  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.781644  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:34.813345  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.031s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1444,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1606,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:34.814103  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling LogGCOp(50de5e78a3b6432088f8b5b5ff124376): free 108988513 bytes of WAL
I20260812 06:17:34.814329  7626 log_reader.cc:385] T 50de5e78a3b6432088f8b5b5ff124376: removed 11 log segments from log reader
I20260812 06:17:34.814373  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000015 (ops 71-75)
I20260812 06:17:34.814401  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000016 (ops 76-80)
I20260812 06:17:34.814471  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000017 (ops 81-84)
I20260812 06:17:34.814513  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000018 (ops 85-89)
I20260812 06:17:34.814555  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000019 (ops 90-94)
I20260812 06:17:34.814618  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000020 (ops 95-99)
I20260812 06:17:34.814654  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000021 (ops 100-104)
I20260812 06:17:34.814713  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000022 (ops 105-109)
I20260812 06:17:34.814752  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000023 (ops 110-114)
I20260812 06:17:34.814792  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000024 (ops 115-119)
I20260812 06:17:34.814831  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000025 (ops 120-124)
I20260812 06:17:34.837530  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: LogGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:34.837976  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.859862  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.022s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.860396  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376): 447 bytes on disk
I20260812 06:17:34.860872  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.861392  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:34.872877  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.873690  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:35.063274  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.189s	user 0.138s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":194,"lbm_read_time_us":14908,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37774,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:17:35.064002  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:35.123723  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.060s	user 0.044s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25284,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.124341  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:35.141244  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.142021  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:35.314472  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.172s	user 0.124s	sys 0.039s 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":1011,"lbm_read_time_us":11125,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30925,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27776,"update_count":2500}
I20260812 06:17:35.315171  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:35.388522  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.073s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26731,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.389119  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:35.400408  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.400980  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:35.593829  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.193s	user 0.147s	sys 0.040s 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":820,"lbm_read_time_us":13984,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32514,"lbm_writes_lt_1ms":543,"mutex_wait_us":321,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:35.594556  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:35.660049  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.065s	user 0.050s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30542,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.660511  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:35.674139  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.674678  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:35.858440  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.184s	user 0.107s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":14844,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33513,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64000,"update_count":2500}
I20260812 06:17:35.859066  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:35.928862  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.070s	user 0.039s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27851,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.929448  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:35.940737  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.941457  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:36.122932  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.181s	user 0.120s	sys 0.058s 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":640,"lbm_read_time_us":14713,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31688,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:36.123579  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=11.118625
I20260812 06:17:36.165649  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.042s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15805,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.167560  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:36.191133  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.023s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.191687  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:36.206888  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.207561  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:36.393149  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.185s	user 0.129s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":634,"lbm_read_time_us":14817,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32206,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:17:36.393904  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=10.126437
I20260812 06:17:36.435817  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.042s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17990,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:17:36.436607  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:36.449033  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.449515  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:36.483487  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushMRSOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":314,"dirs.run_wall_time_us":1250,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2131,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:36.484340  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling LogGCOp(50de5e78a3b6432088f8b5b5ff124376): free 136275439 bytes of WAL
I20260812 06:17:36.484601  7626 log_reader.cc:385] T 50de5e78a3b6432088f8b5b5ff124376: removed 13 log segments from log reader
I20260812 06:17:36.484670  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000026 (ops 125-129)
I20260812 06:17:36.484720  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000027 (ops 130-134)
I20260812 06:17:36.484777  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000028 (ops 135-139)
I20260812 06:17:36.484819  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000029 (ops 140-144)
I20260812 06:17:36.484858  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000030 (ops 145-149)
I20260812 06:17:36.484897  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000031 (ops 150-154)
I20260812 06:17:36.484936  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000032 (ops 155-159)
I20260812 06:17:36.484974  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000033 (ops 160-164)
I20260812 06:17:36.485016  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000034 (ops 165-169)
I20260812 06:17:36.485055  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000035 (ops 170-174)
I20260812 06:17:36.485095  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000036 (ops 175-179)
I20260812 06:17:36.485133  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000037 (ops 180-184)
I20260812 06:17:36.485172  7626 log.cc:1079] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/50de5e78a3b6432088f8b5b5ff124376/wal-000000038 (ops 185-188)
I20260812 06:17:36.512599  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: LogGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:36.513100  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=3.181125
I20260812 06:17:36.532198  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.019s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4895,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.532737  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376): 482 bytes on disk
I20260812 06:17:36.533196  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: UndoDeltaBlockGCOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.533738  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:36.544397  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.544878  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:36.743954  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.199s	user 0.141s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":805,"lbm_read_time_us":15084,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35666,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:36.744582  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=14.095187
I20260812 06:17:36.801313  7435 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.083s	user 1.849s	sys 0.154s
I20260812 06:17:36.813629  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.069s	user 0.020s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23267,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.814157  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376): perf score=2.188937
I20260812 06:17:36.824411  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: FlushDeltaMemStoresOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":500}
I20260812 06:17:36.824856  7728 maintenance_manager.cc:419] P 9be222b6031d42a0a2a6477a69ba1a90: Scheduling MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376): perf score=1.000000
I20260812 06:17:36.886430  7435 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.001s	sys 0.000s
I20260812 06:17:36.887173  7435 tablet_server.cc:179] TabletServer@127.7.66.193:0 shutting down...
I20260812 06:17:36.963806  7626 maintenance_manager.cc:643] P 9be222b6031d42a0a2a6477a69ba1a90: MajorDeltaCompactionOp(50de5e78a3b6432088f8b5b5ff124376) complete. Timing: real 0.139s	user 0.091s	sys 0.047s Metrics: {"cfile_cache_hit":241,"cfile_cache_hit_bytes":9848007,"cfile_cache_miss":291,"cfile_cache_miss_bytes":14926681,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":8136,"lbm_reads_lt_1ms":323,"lbm_write_time_us":26997,"lbm_writes_lt_1ms":543,"mutex_wait_us":380,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":783232,"update_count":2500}
I20260812 06:17:36.964625  7435 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:36.965080  7435 tablet_replica.cc:333] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90: stopping tablet replica
I20260812 06:17:36.965351  7435 raft_consensus.cc:2243] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.965600  7435 raft_consensus.cc:2272] T 50de5e78a3b6432088f8b5b5ff124376 P 9be222b6031d42a0a2a6477a69ba1a90 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.972303  7435 tablet_server.cc:196] TabletServer@127.7.66.193:0 shutdown complete.
I20260812 06:17:37.010360  7435 master.cc:562] Master@127.7.66.254:46111 shutting down...
I20260812 06:17:37.014320  7435 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.014533  7435 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.014638  7435 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8e9ac39ebca841df819069f048f061d7: stopping tablet replica
I20260812 06:17:37.026996  7435 master.cc:584] Master@127.7.66.254:46111 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5750 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:37.117465  7435 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.66.254:40847
I20260812 06:17:37.117903  7435 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:37.120388  7800 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:37.120478  7435 server_base.cc:1061] running on GCE node
W20260812 06:17:37.120565  7795 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:37.120576  7791 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:37.120836  7435 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:37.120879  7435 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:37.120931  7435 hybrid_clock.cc:648] HybridClock initialized: now 1786515457120930 us; error 0 us; skew 500 ppm
I20260812 06:17:37.121804  7435 webserver.cc:533] Webserver started at http://127.7.66.254:41879/ using document root <none> and password file <none>
I20260812 06:17:37.121985  7435 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:37.122046  7435 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:37.122149  7435 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:37.122601  7435 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/master-0-root/instance:
uuid: "e49190905e464c1ea3ac5bb79585439f"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-7f01"
I20260812 06:17:37.124181  7435 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:37.125111  7808 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:37.125370  7435 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:37.125442  7435 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/master-0-root
uuid: "e49190905e464c1ea3ac5bb79585439f"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-7f01"
I20260812 06:17:37.125538  7435 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-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:37.135113  7435 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:37.135507  7435 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:37.139797  7435 rpc_server.cc:307] RPC server started. Bound to: 127.7.66.254:40847
I20260812 06:17:37.150506  7911 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.66.254:40847 every 8 connection(s)
I20260812 06:17:37.150789  7912 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:37.157428  7912 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f: Bootstrap starting.
I20260812 06:17:37.158332  7912 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:37.159479  7912 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f: No bootstrap required, opened a new log
I20260812 06:17:37.159926  7912 raft_consensus.cc:359] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER }
I20260812 06:17:37.160043  7912 raft_consensus.cc:385] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:37.160094  7912 raft_consensus.cc:740] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e49190905e464c1ea3ac5bb79585439f, State: Initialized, Role: FOLLOWER
I20260812 06:17:37.160284  7912 consensus_queue.cc:260] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [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: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER }
I20260812 06:17:37.160396  7912 raft_consensus.cc:399] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:37.160452  7912 raft_consensus.cc:493] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:37.160508  7912 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:37.161226  7912 raft_consensus.cc:515] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER }
I20260812 06:17:37.161386  7912 leader_election.cc:304] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [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: e49190905e464c1ea3ac5bb79585439f; no voters: 
I20260812 06:17:37.161605  7912 leader_election.cc:290] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:37.161747  7918 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:37.161960  7918 raft_consensus.cc:697] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 1 LEADER]: Becoming Leader. State: Replica: e49190905e464c1ea3ac5bb79585439f, State: Running, Role: LEADER
I20260812 06:17:37.162081  7912 sys_catalog.cc:565] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:37.162096  7918 consensus_queue.cc:237] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [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: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER }
I20260812 06:17:37.162575  7920 sys_catalog.cc:455] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [sys.catalog]: SysCatalogTable state changed. Reason: New leader e49190905e464c1ea3ac5bb79585439f. Latest consensus state: current_term: 1 leader_uuid: "e49190905e464c1ea3ac5bb79585439f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER } }
I20260812 06:17:37.162669  7920 sys_catalog.cc:458] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:37.162559  7919 sys_catalog.cc:455] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e49190905e464c1ea3ac5bb79585439f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49190905e464c1ea3ac5bb79585439f" member_type: VOTER } }
I20260812 06:17:37.162971  7919 sys_catalog.cc:458] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:37.163050  7925 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:37.163909  7925 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:37.164191  7435 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:37.165796  7925 catalog_manager.cc:1383] Generated new cluster ID: 4258e91f0b464f9b920d8afb3ce1ab48
I20260812 06:17:37.165858  7925 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:37.184204  7925 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:37.184783  7925 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:37.190362  7925 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f: Generated new TSK 0
I20260812 06:17:37.190569  7925 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:37.196558  7435 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:37.198877  7957 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:37.198868  7959 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:37.198900  7435 server_base.cc:1061] running on GCE node
W20260812 06:17:37.198863  7956 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:37.199338  7435 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:37.199388  7435 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:37.199404  7435 hybrid_clock.cc:648] HybridClock initialized: now 1786515457199404 us; error 0 us; skew 500 ppm
I20260812 06:17:37.200601  7435 webserver.cc:533] Webserver started at http://127.7.66.193:32967/ using document root <none> and password file <none>
I20260812 06:17:37.200819  7435 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:37.200913  7435 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:37.201021  7435 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:37.201448  7435 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/instance:
uuid: "f134e6bee60f4256aa23127fa6c9c261"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-7f01"
I20260812 06:17:37.203012  7435 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:37.204032  7966 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:37.204298  7435 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:37.204388  7435 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root
uuid: "f134e6bee60f4256aa23127fa6c9c261"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-7f01"
I20260812 06:17:37.204484  7435 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-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:37.219122  7435 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:37.219560  7435 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:37.219966  7435 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:37.220466  7435 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:37.220531  7435 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:37.220592  7435 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:37.220641  7435 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:37.224778  7435 rpc_server.cc:307] RPC server started. Bound to: 127.7.66.193:36167
I20260812 06:17:37.224838  8092 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.66.193:36167 every 8 connection(s)
I20260812 06:17:37.232916  8094 heartbeater.cc:344] Connected to a master server at 127.7.66.254:40847
I20260812 06:17:37.233053  8094 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:37.233289  8094 heartbeater.cc:507] Master 127.7.66.254:40847 requested a full tablet report, sending...
I20260812 06:17:37.233937  7840 ts_manager.cc:194] Registered new tserver with Master: f134e6bee60f4256aa23127fa6c9c261 (127.7.66.193:36167)
I20260812 06:17:37.234211  7435 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008922023s
I20260812 06:17:37.234778  7840 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40666
I20260812 06:17:37.241452  7840 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40672:
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:37.250658  8022 tablet_service.cc:1511] Processing CreateTablet for tablet dda20225d48e438db2b014278eb32b9e (DEFAULT_TABLE table=heavy-update-compaction-test [id=5a1c25a0afba4aaea48118a8b792334a]), partition=
I20260812 06:17:37.250972  8022 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dda20225d48e438db2b014278eb32b9e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:37.253167  8124 tablet_bootstrap.cc:492] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Bootstrap starting.
I20260812 06:17:37.254029  8124 tablet_bootstrap.cc:654] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:37.255064  8124 tablet_bootstrap.cc:492] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: No bootstrap required, opened a new log
I20260812 06:17:37.255184  8124 ts_tablet_manager.cc:1403] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:37.255662  8124 raft_consensus.cc:359] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f134e6bee60f4256aa23127fa6c9c261" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 36167 } }
I20260812 06:17:37.255805  8124 raft_consensus.cc:385] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:37.255910  8124 raft_consensus.cc:740] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f134e6bee60f4256aa23127fa6c9c261, State: Initialized, Role: FOLLOWER
I20260812 06:17:37.256124  8124 consensus_queue.cc:260] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [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: "f134e6bee60f4256aa23127fa6c9c261" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 36167 } }
I20260812 06:17:37.256227  8124 raft_consensus.cc:399] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:37.256270  8124 raft_consensus.cc:493] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:37.256325  8124 raft_consensus.cc:3060] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:37.257023  8124 raft_consensus.cc:515] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f134e6bee60f4256aa23127fa6c9c261" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 36167 } }
I20260812 06:17:37.257140  8124 leader_election.cc:304] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [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: f134e6bee60f4256aa23127fa6c9c261; no voters: 
I20260812 06:17:37.257289  8124 leader_election.cc:290] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:37.257432  8130 raft_consensus.cc:2804] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:37.257639  8130 raft_consensus.cc:697] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 1 LEADER]: Becoming Leader. State: Replica: f134e6bee60f4256aa23127fa6c9c261, State: Running, Role: LEADER
I20260812 06:17:37.257702  8094 heartbeater.cc:499] Master 127.7.66.254:40847 was elected leader, sending a full tablet report...
I20260812 06:17:37.257655  8124 ts_tablet_manager.cc:1434] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:37.257848  8130 consensus_queue.cc:237] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [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: "f134e6bee60f4256aa23127fa6c9c261" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 36167 } }
I20260812 06:17:37.259160  7840 catalog_manager.cc:5719] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 reported cstate change: term changed from 0 to 1, leader changed from <none> to f134e6bee60f4256aa23127fa6c9c261 (127.7.66.193). New cstate: current_term: 1 leader_uuid: "f134e6bee60f4256aa23127fa6c9c261" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f134e6bee60f4256aa23127fa6c9c261" member_type: VOTER last_known_addr { host: "127.7.66.193" port: 36167 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:37.321789  7435 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.014s	sys 0.008s
I20260812 06:17:37.475960  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushMRSOp(dda20225d48e438db2b014278eb32b9e): perf score=19.054940
I20260812 06:17:37.641249  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushMRSOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.165s	user 0.131s	sys 0.032s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":676,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45524,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:37.641942  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling LogGCOp(dda20225d48e438db2b014278eb32b9e): free 20743880 bytes of WAL
I20260812 06:17:37.642181  7974 log_reader.cc:385] T dda20225d48e438db2b014278eb32b9e: removed 2 log segments from log reader
I20260812 06:17:37.642249  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000001 (ops 1-6)
I20260812 06:17:37.642307  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000002 (ops 7-11)
I20260812 06:17:37.648530  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: LogGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:17:37.648970  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:37.665474  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.666042  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:37.823033  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.157s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":550,"lbm_read_time_us":11055,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28065,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":355,"threads_started":5,"update_count":2000}
I20260812 06:17:37.823681  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e): 16411395 bytes on disk
I20260812 06:17:37.824157  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.824618  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=11.118625
I20260812 06:17:37.864373  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17924,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.864938  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:37.883311  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.883987  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.018393  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.134s	user 0.100s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":388,"lbm_read_time_us":8141,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23803,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:38.019723  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:38.067592  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.047s	user 0.016s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21254,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.068194  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.082973  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.083433  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.217178  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.134s	user 0.106s	sys 0.028s 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":1150,"lbm_read_time_us":10708,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25814,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:38.217947  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:38.270896  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.052s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.271525  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.282883  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.283398  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.450296  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.167s	user 0.122s	sys 0.044s 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":424,"lbm_read_time_us":11839,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26149,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:17:38.450871  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:38.489507  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.038s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.489964  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.500581  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.501166  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.631294  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.130s	user 0.102s	sys 0.028s 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":1001,"lbm_read_time_us":9518,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25230,"lbm_writes_lt_1ms":443,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2000}
I20260812 06:17:38.631927  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:38.672461  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.040s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16934,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.673000  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.684120  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.684754  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.820200  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.135s	user 0.107s	sys 0.028s 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":742,"lbm_read_time_us":8973,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27929,"lbm_writes_lt_1ms":443,"mutex_wait_us":259,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:17:38.820837  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:38.876638  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.056s	user 0.035s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16887,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.877192  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.888273  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.888976  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushMRSOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:38.933210  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushMRSOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.044s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1485,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1579,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:38.933815  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling LogGCOp(dda20225d48e438db2b014278eb32b9e): free 112692367 bytes of WAL
I20260812 06:17:38.934036  7974 log_reader.cc:385] T dda20225d48e438db2b014278eb32b9e: removed 11 log segments from log reader
I20260812 06:17:38.934077  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000003 (ops 12-16)
I20260812 06:17:38.934106  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000004 (ops 17-21)
I20260812 06:17:38.934173  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000005 (ops 22-26)
I20260812 06:17:38.934216  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000006 (ops 27-31)
I20260812 06:17:38.934262  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000007 (ops 32-36)
I20260812 06:17:38.934319  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000008 (ops 37-41)
I20260812 06:17:38.934356  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000009 (ops 42-46)
I20260812 06:17:38.934397  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000010 (ops 47-51)
I20260812 06:17:38.934432  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000011 (ops 52-56)
I20260812 06:17:38.934471  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000012 (ops 57-61)
I20260812 06:17:38.934516  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000013 (ops 62-66)
I20260812 06:17:38.959146  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: LogGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:38.959535  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e): 447 bytes on disk
I20260812 06:17:38.959995  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.960505  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=3.181125
I20260812 06:17:38.981835  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.021s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4766,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:38.982312  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:38.992846  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.993280  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:39.217481  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.224s	user 0.152s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":381,"lbm_read_time_us":16602,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35942,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:17:39.220180  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=15.087375
I20260812 06:17:39.279886  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.059s	user 0.034s	sys 0.025s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":28414,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:17:39.280405  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:39.297617  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.298076  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:39.308964  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3889,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.309407  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:39.509409  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.200s	user 0.133s	sys 0.066s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":508,"lbm_read_time_us":14058,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32823,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":3000}
I20260812 06:17:39.512833  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=15.087375
I20260812 06:17:39.580926  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.067s	user 0.022s	sys 0.029s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23366,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:39.581410  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=6.157687
I20260812 06:17:39.607354  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.026s	user 0.017s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10554,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:39.608018  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:39.837172  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.229s	user 0.132s	sys 0.086s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1830,"lbm_read_time_us":14922,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37393,"lbm_writes_lt_1ms":643,"mutex_wait_us":721,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":3000}
I20260812 06:17:39.837968  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=18.063937
I20260812 06:17:39.913661  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.075s	user 0.054s	sys 0.019s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":32373,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:39.914275  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:39.939524  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.025s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.940079  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:39.950655  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.951134  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:40.178382  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.227s	user 0.154s	sys 0.073s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979636,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":870,"lbm_read_time_us":16448,"lbm_reads_lt_1ms":773,"lbm_write_time_us":43086,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":3500}
I20260812 06:17:40.179190  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=18.063937
I20260812 06:17:40.246572  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.067s	user 0.040s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30906,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.247217  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:40.260812  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.261404  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:40.429869  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.168s	user 0.129s	sys 0.039s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":12766,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33533,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:17:40.430680  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=14.095187
I20260812 06:17:40.471459  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.041s	user 0.016s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.472386  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:40.491472  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.019s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6538,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.492105  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushMRSOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:40.537205  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushMRSOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.045s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":369,"dirs.run_wall_time_us":1505,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3003,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:40.538178  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e): 507 bytes on disk
I20260812 06:17:40.538600  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.539135  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=3.181125
I20260812 06:17:40.556945  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7196,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:40.557395  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling LogGCOp(dda20225d48e438db2b014278eb32b9e): free 133024372 bytes of WAL
I20260812 06:17:40.557606  7974 log_reader.cc:385] T dda20225d48e438db2b014278eb32b9e: removed 13 log segments from log reader
I20260812 06:17:40.557646  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000014 (ops 67-71)
I20260812 06:17:40.557675  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000015 (ops 72-76)
I20260812 06:17:40.557739  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000016 (ops 77-81)
I20260812 06:17:40.557780  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000017 (ops 82-86)
I20260812 06:17:40.557821  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000018 (ops 87-91)
I20260812 06:17:40.557864  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000019 (ops 92-96)
I20260812 06:17:40.557905  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000020 (ops 97-101)
I20260812 06:17:40.557945  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000021 (ops 102-106)
I20260812 06:17:40.557986  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000022 (ops 107-111)
I20260812 06:17:40.558024  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000023 (ops 112-116)
I20260812 06:17:40.558063  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000024 (ops 117-120)
I20260812 06:17:40.558101  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000025 (ops 121-125)
I20260812 06:17:40.558140  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000026 (ops 126-130)
I20260812 06:17:40.589005  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: LogGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:40.589534  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:40.606844  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.607312  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling LogGCOp(dda20225d48e438db2b014278eb32b9e): free 11564893 bytes of WAL
I20260812 06:17:40.607514  7974 log_reader.cc:385] T dda20225d48e438db2b014278eb32b9e: removed 1 log segments from log reader
I20260812 06:17:40.607554  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000027 (ops 131-134)
I20260812 06:17:40.609956  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: LogGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:40.610236  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:40.620884  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3775,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.621536  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:40.867705  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.246s	user 0.175s	sys 0.059s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1378,"lbm_read_time_us":17033,"lbm_reads_lt_1ms":875,"lbm_write_time_us":50216,"lbm_writes_lt_1ms":843,"mutex_wait_us":64,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:17:40.868458  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=18.063937
I20260812 06:17:40.922070  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.053s	user 0.025s	sys 0.026s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24281,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.922621  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:40.937162  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.937611  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:41.112933  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.175s	user 0.139s	sys 0.036s 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":442,"lbm_read_time_us":12317,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36071,"lbm_writes_lt_1ms":643,"mutex_wait_us":87,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:17:41.117481  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=14.095187
I20260812 06:17:41.160882  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.043s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19389,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.161478  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:41.179095  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.179636  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:41.346599  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.167s	user 0.114s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":10215,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31421,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44928,"update_count":2500}
I20260812 06:17:41.347191  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=14.095187
I20260812 06:17:41.396770  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.049s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22116,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.397501  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:41.546129  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.148s	user 0.092s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":421,"lbm_read_time_us":11833,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24721,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":2000}
I20260812 06:17:41.548235  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:41.589349  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.041s	user 0.015s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18492,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.589902  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:41.610504  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.020s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.610996  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:41.742398  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.131s	user 0.119s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":9526,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26823,"lbm_writes_lt_1ms":443,"mutex_wait_us":343,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:41.743271  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:41.782595  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16874,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.783150  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:41.800689  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.801385  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:41.933236  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.132s	user 0.091s	sys 0.040s 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":797,"lbm_read_time_us":9533,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25176,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":411520,"update_count":2000}
I20260812 06:17:41.934170  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=10.126437
I20260812 06:17:41.980893  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.046s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16346,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.981457  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:41.998068  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.998864  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushMRSOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:42.029398  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushMRSOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1210,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1660,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:42.030090  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling LogGCOp(dda20225d48e438db2b014278eb32b9e): free 116849766 bytes of WAL
I20260812 06:17:42.030305  7974 log_reader.cc:385] T dda20225d48e438db2b014278eb32b9e: removed 12 log segments from log reader
I20260812 06:17:42.030346  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000028 (ops 135-139)
I20260812 06:17:42.030375  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000029 (ops 140-144)
I20260812 06:17:42.030433  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000030 (ops 145-148)
I20260812 06:17:42.030494  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000031 (ops 149-153)
I20260812 06:17:42.030534  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000032 (ops 154-158)
I20260812 06:17:42.030571  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000033 (ops 159-163)
I20260812 06:17:42.030611  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000034 (ops 164-168)
I20260812 06:17:42.030648  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000035 (ops 169-172)
I20260812 06:17:42.030692  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000036 (ops 173-177)
I20260812 06:17:42.030731  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000037 (ops 178-182)
I20260812 06:17:42.030768  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000038 (ops 183-186)
I20260812 06:17:42.030807  7974 log.cc:1079] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: Deleting log segment in path: /tmp/dist-test-task83JK6P/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515451356300-7435-0/minicluster-data/ts-0-root/wals/dda20225d48e438db2b014278eb32b9e/wal-000000039 (ops 187-191)
I20260812 06:17:42.057494  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: LogGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:42.058027  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e): 462 bytes on disk
I20260812 06:17:42.058549  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: UndoDeltaBlockGCOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.059136  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=3.181125
I20260812 06:17:42.076853  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7045,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:42.077327  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=2.188937
I20260812 06:17:42.091583  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5606,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.092105  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e): perf score=1.000000
I20260812 06:17:42.277887  7435 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.956s	user 1.882s	sys 0.136s
I20260812 06:17:42.280354  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: MajorDeltaCompactionOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.188s	user 0.139s	sys 0.048s 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":483,"lbm_read_time_us":14657,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38451,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:17:42.283327  8100 maintenance_manager.cc:419] P f134e6bee60f4256aa23127fa6c9c261: Scheduling FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e): perf score=14.095187
I20260812 06:17:42.310163  7435 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.032s	user 0.001s	sys 0.004s
I20260812 06:17:42.313201  7435 tablet_server.cc:179] TabletServer@127.7.66.193:0 shutting down...
I20260812 06:17:42.333310  7974 maintenance_manager.cc:643] P f134e6bee60f4256aa23127fa6c9c261: FlushDeltaMemStoresOp(dda20225d48e438db2b014278eb32b9e) complete. Timing: real 0.050s	user 0.016s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23160,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.333889  7435 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:42.334097  7435 tablet_replica.cc:333] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261: stopping tablet replica
I20260812 06:17:42.334270  7435 raft_consensus.cc:2243] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:42.334444  7435 raft_consensus.cc:2272] T dda20225d48e438db2b014278eb32b9e P f134e6bee60f4256aa23127fa6c9c261 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:42.338008  7435 tablet_server.cc:196] TabletServer@127.7.66.193:0 shutdown complete.
I20260812 06:17:42.340885  7435 master.cc:562] Master@127.7.66.254:40847 shutting down...
I20260812 06:17:42.343808  7435 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:42.343981  7435 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:42.344069  7435 tablet_replica.cc:333] T 00000000000000000000000000000000 P e49190905e464c1ea3ac5bb79585439f: stopping tablet replica
I20260812 06:17:42.356343  7435 master.cc:584] Master@127.7.66.254:40847 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5326 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11078 ms total)

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