[==========] 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:18:35.287593 11653 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.97.126:46777
I20260812 06:18:35.288599 11653 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:18:35.289197 11653 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:35.295490 11659 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:18:35.295514 11660 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:18:35.295738 11662 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:18:35.295775 11653 server_base.cc:1061] running on GCE node
I20260812 06:18:35.296239 11653 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:35.296375 11653 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:18:35.296411 11653 hybrid_clock.cc:648] HybridClock initialized: now 1786515515296409 us; error 0 us; skew 500 ppm
I20260812 06:18:35.298135 11653 webserver.cc:533] Webserver started at http://127.11.97.126:44673/ using document root <none> and password file <none>
I20260812 06:18:35.298627 11653 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:35.298684 11653 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:35.298938 11653 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:35.300513 11653 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/master-0-root/instance:
uuid: "9113faea3eb64b2b9d3f558883fb458f"
format_stamp: "Formatted at 2026-08-12 06:18:35 on dist-test-slave-39l8"
I20260812 06:18:35.303915 11653 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:35.305912 11671 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:18:35.307006 11653 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:35.307152 11653 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/master-0-root
uuid: "9113faea3eb64b2b9d3f558883fb458f"
format_stamp: "Formatted at 2026-08-12 06:18:35 on dist-test-slave-39l8"
I20260812 06:18:35.307269 11653 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-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:18:35.328018 11653 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:35.328680 11653 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:18:35.328869 11653 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:35.336831 11653 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.126:46777
I20260812 06:18:35.336886 11756 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.126:46777 every 8 connection(s)
I20260812 06:18:35.339160 11757 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:18:35.344437 11757 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: Bootstrap starting.
I20260812 06:18:35.346868 11757 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:35.347800 11757 log.cc:826] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:35.349473 11757 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: No bootstrap required, opened a new log
I20260812 06:18:35.352315 11757 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER }
I20260812 06:18:35.352478 11757 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:35.352596 11757 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9113faea3eb64b2b9d3f558883fb458f, State: Initialized, Role: FOLLOWER
I20260812 06:18:35.353246 11757 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [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: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER }
I20260812 06:18:35.353415 11757 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:35.353500 11757 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:35.353677 11757 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:35.354493 11757 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER }
I20260812 06:18:35.355000 11757 leader_election.cc:304] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [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: 9113faea3eb64b2b9d3f558883fb458f; no voters: 
I20260812 06:18:35.355352 11757 leader_election.cc:290] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:35.355515 11763 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:35.355788 11763 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 1 LEADER]: Becoming Leader. State: Replica: 9113faea3eb64b2b9d3f558883fb458f, State: Running, Role: LEADER
I20260812 06:18:35.356218 11763 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [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: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER }
I20260812 06:18:35.356370 11757 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:35.358150 11765 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9113faea3eb64b2b9d3f558883fb458f. Latest consensus state: current_term: 1 leader_uuid: "9113faea3eb64b2b9d3f558883fb458f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER } }
I20260812 06:18:35.358196 11764 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9113faea3eb64b2b9d3f558883fb458f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9113faea3eb64b2b9d3f558883fb458f" member_type: VOTER } }
I20260812 06:18:35.358325 11765 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:35.358333 11764 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:35.358687 11775 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:35.360924 11775 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:35.361234 11653 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:35.365984 11775 catalog_manager.cc:1383] Generated new cluster ID: 6102b14a75f2476e8a575c8ffc7cedaf
I20260812 06:18:35.366070 11775 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:35.377892 11775 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:35.378695 11775 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:35.391366 11775 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: Generated new TSK 0
I20260812 06:18:35.392040 11775 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:35.393692 11653 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:35.396157 11793 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:18:35.396324 11796 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:18:35.396301 11792 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:18:35.396443 11653 server_base.cc:1061] running on GCE node
I20260812 06:18:35.396680 11653 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:35.396729 11653 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:18:35.396745 11653 hybrid_clock.cc:648] HybridClock initialized: now 1786515515396745 us; error 0 us; skew 500 ppm
I20260812 06:18:35.397680 11653 webserver.cc:533] Webserver started at http://127.11.97.65:36725/ using document root <none> and password file <none>
I20260812 06:18:35.397873 11653 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:35.397928 11653 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:35.398020 11653 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:35.398415 11653 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/instance:
uuid: "aab838f733764a4d992034e83fa74ad6"
format_stamp: "Formatted at 2026-08-12 06:18:35 on dist-test-slave-39l8"
I20260812 06:18:35.400002 11653 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:35.401029 11803 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:18:35.401286 11653 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:35.401374 11653 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root
uuid: "aab838f733764a4d992034e83fa74ad6"
format_stamp: "Formatted at 2026-08-12 06:18:35 on dist-test-slave-39l8"
I20260812 06:18:35.401465 11653 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-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:18:35.422585 11653 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:35.423097 11653 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:35.423565 11653 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:35.424455 11653 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:35.424530 11653 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:35.424605 11653 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:35.424646 11653 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:35.431409 11653 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.65:38773
I20260812 06:18:35.431449 11914 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.65:38773 every 8 connection(s)
I20260812 06:18:35.448362 11916 heartbeater.cc:344] Connected to a master server at 127.11.97.126:46777
I20260812 06:18:35.448654 11916 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:35.449116 11916 heartbeater.cc:507] Master 127.11.97.126:46777 requested a full tablet report, sending...
I20260812 06:18:35.450536 11704 ts_manager.cc:194] Registered new tserver with Master: aab838f733764a4d992034e83fa74ad6 (127.11.97.65:38773)
I20260812 06:18:35.450807 11653 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01875747s
I20260812 06:18:35.452181 11704 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46494
I20260812 06:18:35.460316 11704 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46508:
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:18:35.473865 11855 tablet_service.cc:1511] Processing CreateTablet for tablet beff0c1bc50747a990e3f4ca59efcc08 (DEFAULT_TABLE table=heavy-update-compaction-test [id=190c85e0baf24583ab6af8cd2f6efba8]), partition=
I20260812 06:18:35.474345 11855 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet beff0c1bc50747a990e3f4ca59efcc08. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:35.476527 11932 tablet_bootstrap.cc:492] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Bootstrap starting.
I20260812 06:18:35.477502 11932 tablet_bootstrap.cc:654] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:35.478684 11932 tablet_bootstrap.cc:492] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: No bootstrap required, opened a new log
I20260812 06:18:35.478852 11932 ts_tablet_manager.cc:1403] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:35.479286 11932 raft_consensus.cc:359] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aab838f733764a4d992034e83fa74ad6" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 38773 } }
I20260812 06:18:35.479382 11932 raft_consensus.cc:385] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:35.479405 11932 raft_consensus.cc:740] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aab838f733764a4d992034e83fa74ad6, State: Initialized, Role: FOLLOWER
I20260812 06:18:35.479580 11932 consensus_queue.cc:260] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [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: "aab838f733764a4d992034e83fa74ad6" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 38773 } }
I20260812 06:18:35.479653 11932 raft_consensus.cc:399] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:35.479707 11932 raft_consensus.cc:493] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:35.479763 11932 raft_consensus.cc:3060] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:35.480784 11932 raft_consensus.cc:515] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aab838f733764a4d992034e83fa74ad6" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 38773 } }
I20260812 06:18:35.480901 11932 leader_election.cc:304] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [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: aab838f733764a4d992034e83fa74ad6; no voters: 
I20260812 06:18:35.481169 11932 leader_election.cc:290] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:35.481266 11934 raft_consensus.cc:2804] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:35.481448 11934 raft_consensus.cc:697] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 1 LEADER]: Becoming Leader. State: Replica: aab838f733764a4d992034e83fa74ad6, State: Running, Role: LEADER
I20260812 06:18:35.481531 11932 ts_tablet_manager.cc:1434] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:35.481572 11934 consensus_queue.cc:237] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [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: "aab838f733764a4d992034e83fa74ad6" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 38773 } }
I20260812 06:18:35.482076 11916 heartbeater.cc:499] Master 127.11.97.126:46777 was elected leader, sending a full tablet report...
I20260812 06:18:35.484565 11704 catalog_manager.cc:5719] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 reported cstate change: term changed from 0 to 1, leader changed from <none> to aab838f733764a4d992034e83fa74ad6 (127.11.97.65). New cstate: current_term: 1 leader_uuid: "aab838f733764a4d992034e83fa74ad6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aab838f733764a4d992034e83fa74ad6" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 38773 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:35.559194 11653 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.025s	sys 0.009s
I20260812 06:18:35.682592 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=15.086190
I20260812 06:18:35.864763 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.182s	user 0.148s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":348,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":795,"drs_written":1,"lbm_read_time_us":228,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43694,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":128,"threads_started":1,"update_count":1500}
I20260812 06:18:35.866155 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling LogGCOp(beff0c1bc50747a990e3f4ca59efcc08): free 20743880 bytes of WAL
I20260812 06:18:35.866605 11811 log_reader.cc:385] T beff0c1bc50747a990e3f4ca59efcc08: removed 2 log segments from log reader
I20260812 06:18:35.866789 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000001 (ops 1-6)
I20260812 06:18:35.866927 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000002 (ops 7-11)
I20260812 06:18:35.872584 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: LogGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:35.873039 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=3.181125
I20260812 06:18:35.906353 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.033s	user 0.007s	sys 0.016s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6842,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:35.907114 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08): 16411393 bytes on disk
I20260812 06:18:35.907912 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.908473 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:35.921645 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5146,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.922057 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:36.104825 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.183s	user 0.115s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":435,"lbm_read_time_us":12110,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29981,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":238,"threads_started":5,"update_count":2500}
I20260812 06:18:36.105327 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:36.161059 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.056s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25830,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.161619 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.184689 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.023s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6349,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.185269 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.195547 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.195993 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:36.365157 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.169s	user 0.123s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774806,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":525,"lbm_read_time_us":11181,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28043,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:18:36.365629 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:36.401304 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15249,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.401880 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.418238 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.418692 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:36.542387 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.123s	user 0.097s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":534,"lbm_read_time_us":9671,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21661,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":46720,"update_count":2000}
I20260812 06:18:36.543087 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:36.581243 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.038s	user 0.009s	sys 0.026s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14721,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.581709 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.604916 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.023s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.605419 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.619939 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.620448 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:36.765921 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.145s	user 0.124s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774810,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":498,"lbm_read_time_us":11305,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29430,"lbm_writes_lt_1ms":543,"mutex_wait_us":253,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:36.766460 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:36.802527 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.036s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15678,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.803007 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:36.818034 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.818764 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:36.946640 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.128s	user 0.110s	sys 0.017s 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":636,"lbm_read_time_us":8777,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26530,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:18:36.947144 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:36.997514 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.050s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13100,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.998068 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.008916 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.009390 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:37.153332 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.144s	user 0.118s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":316,"lbm_read_time_us":11920,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23517,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.153932 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:37.200242 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.046s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19463,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.200678 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.211556 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.212291 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:37.245177 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1170,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1516,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:37.246002 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling LogGCOp(beff0c1bc50747a990e3f4ca59efcc08): free 120553376 bytes of WAL
I20260812 06:18:37.246243 11811 log_reader.cc:385] T beff0c1bc50747a990e3f4ca59efcc08: removed 12 log segments from log reader
I20260812 06:18:37.246289 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000003 (ops 12-16)
I20260812 06:18:37.246316 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000004 (ops 17-21)
I20260812 06:18:37.246377 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000005 (ops 22-26)
I20260812 06:18:37.246411 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000006 (ops 27-30)
I20260812 06:18:37.246454 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000007 (ops 31-35)
I20260812 06:18:37.246492 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000008 (ops 36-40)
I20260812 06:18:37.246531 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000009 (ops 41-44)
I20260812 06:18:37.246572 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000010 (ops 45-49)
I20260812 06:18:37.246616 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000011 (ops 50-54)
I20260812 06:18:37.246655 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000012 (ops 55-59)
I20260812 06:18:37.246723 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000013 (ops 60-64)
I20260812 06:18:37.246762 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000014 (ops 65-69)
I20260812 06:18:37.274478 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: LogGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:37.275070 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08): 482 bytes on disk
I20260812 06:18:37.275519 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.275955 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=3.181125
I20260812 06:18:37.291399 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.015s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4959,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:37.291888 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.305919 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5333,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.306443 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:37.487516 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.181s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":493,"lbm_read_time_us":13626,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32227,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":71168,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:18:37.488027 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=14.095187
I20260812 06:18:37.546109 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.058s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21227,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.546797 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.558254 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.558691 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:37.734735 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.176s	user 0.112s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":13086,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30387,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:18:37.735381 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=11.118625
I20260812 06:18:37.778945 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.042s	user 0.032s	sys 0.010s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":17293,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.779429 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.815408 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.036s	user 0.012s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5018,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":450}
I20260812 06:18:37.815953 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:37.831918 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.832530 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.005007 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.172s	user 0.120s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":557,"lbm_read_time_us":13478,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28321,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:38.005728 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=11.118625
I20260812 06:18:38.044958 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.039s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17102,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:38.045531 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.059962 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5699,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.060513 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.184357 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.124s	user 0.115s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":8310,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24336,"lbm_writes_lt_1ms":443,"mutex_wait_us":215,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:18:38.184916 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:38.222728 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.038s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15748,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.223603 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.237979 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.238536 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.368386 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.130s	user 0.101s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":715,"lbm_read_time_us":8756,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25206,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.369436 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:38.407574 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.038s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13593,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.408111 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.422993 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.423502 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.544238 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.121s	user 0.096s	sys 0.024s 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":699,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21869,"lbm_writes_lt_1ms":443,"mutex_wait_us":87,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:18:38.545043 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:38.599061 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.054s	user 0.026s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18804,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.599546 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.610339 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.611020 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.648949 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.038s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1232,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1612,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:38.649711 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling LogGCOp(beff0c1bc50747a990e3f4ca59efcc08): free 124710250 bytes of WAL
I20260812 06:18:38.649943 11811 log_reader.cc:385] T beff0c1bc50747a990e3f4ca59efcc08: removed 12 log segments from log reader
I20260812 06:18:38.649992 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000015 (ops 70-74)
I20260812 06:18:38.650024 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000016 (ops 75-79)
I20260812 06:18:38.650087 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000017 (ops 80-84)
I20260812 06:18:38.650132 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000018 (ops 85-89)
I20260812 06:18:38.650179 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000019 (ops 90-94)
I20260812 06:18:38.650238 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000020 (ops 95-99)
I20260812 06:18:38.650295 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000021 (ops 100-104)
I20260812 06:18:38.650331 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000022 (ops 105-109)
I20260812 06:18:38.650369 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000023 (ops 110-114)
I20260812 06:18:38.650408 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000024 (ops 115-119)
I20260812 06:18:38.650447 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000025 (ops 120-124)
I20260812 06:18:38.650490 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000026 (ops 125-129)
I20260812 06:18:38.678964 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: LogGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:38.679383 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08): 447 bytes on disk
I20260812 06:18:38.679981 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:18:38.680765 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.704298 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.023s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.704779 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:38.714994 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.715391 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:38.913659 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.198s	user 0.130s	sys 0.068s 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":355,"lbm_read_time_us":11780,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36082,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:18:38.914345 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=14.095187
I20260812 06:18:38.966580 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22590,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.967227 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:39.114883 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.147s	user 0.117s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":205,"lbm_read_time_us":10441,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25652,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:39.116024 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:39.151714 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.035s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15717,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.152375 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:39.171828 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.172410 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:39.319721 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.147s	user 0.116s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":349,"lbm_read_time_us":11072,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26890,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:39.320611 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:39.351915 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.352807 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:39.368775 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.369267 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:39.491025 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.122s	user 0.092s	sys 0.029s 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":228,"lbm_read_time_us":7802,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25363,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:39.491667 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:39.524417 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14371,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:39.525058 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:39.633124 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.108s	user 0.091s	sys 0.017s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1128,"lbm_read_time_us":7017,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21168,"lbm_writes_lt_1ms":343,"mutex_wait_us":295,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.633741 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:39.677295 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.043s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13394,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.677757 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:39.688705 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.689309 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:39.829046 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.140s	user 0.111s	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":1040,"lbm_read_time_us":9131,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26621,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28288,"update_count":2000}
I20260812 06:18:39.829591 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:39.872577 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.043s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16278,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.873023 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:39.883270 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.884037 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:40.007812 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.124s	user 0.096s	sys 0.024s 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":358,"dirs.run_cpu_time_us":601,"dirs.run_wall_time_us":3278,"lbm_read_time_us":9762,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21903,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:18:40.008739 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=10.126437
I20260812 06:18:40.047260 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.038s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13681,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.047715 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:40.058892 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.011s	user 0.007s	sys 0.004s 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:18:40.059602 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:40.090965 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushMRSOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1249,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:40.091609 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling LogGCOp(beff0c1bc50747a990e3f4ca59efcc08): free 120553690 bytes of WAL
I20260812 06:18:40.091835 11811 log_reader.cc:385] T beff0c1bc50747a990e3f4ca59efcc08: removed 12 log segments from log reader
I20260812 06:18:40.091879 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000027 (ops 130-134)
I20260812 06:18:40.091907 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000028 (ops 135-139)
I20260812 06:18:40.091971 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000029 (ops 140-144)
I20260812 06:18:40.092029 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000030 (ops 145-149)
I20260812 06:18:40.092082 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000031 (ops 150-154)
I20260812 06:18:40.092123 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000032 (ops 155-159)
I20260812 06:18:40.092161 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000033 (ops 160-164)
I20260812 06:18:40.092199 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000034 (ops 165-168)
I20260812 06:18:40.092239 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000035 (ops 169-173)
I20260812 06:18:40.092278 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000036 (ops 174-178)
I20260812 06:18:40.092317 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000037 (ops 179-182)
I20260812 06:18:40.092355 11811 log.cc:1079] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/beff0c1bc50747a990e3f4ca59efcc08/wal-000000038 (ops 183-187)
I20260812 06:18:40.118829 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: LogGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.027s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:18:40.119285 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=5.165500
I20260812 06:18:40.134853 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":6523086,"delete_count":0,"lbm_write_time_us":6615,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:18:40.135488 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:40.142607 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.007s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1682177,"delete_count":0,"lbm_write_time_us":2296,"lbm_writes_lt_1ms":44,"reinsert_count":0,"update_count":205}
I20260812 06:18:40.143074 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08): 463 bytes on disk
I20260812 06:18:40.143465 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: UndoDeltaBlockGCOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.143970 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:40.307598 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.163s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":656,"lbm_read_time_us":12900,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31410,"lbm_writes_lt_1ms":643,"mutex_wait_us":279,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:18:40.308221 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=14.095187
I20260812 06:18:40.349952 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.042s	user 0.028s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17650,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.350522 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=2.188937
I20260812 06:18:40.365842 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: FlushDeltaMemStoresOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.366357 11918 maintenance_manager.cc:419] P aab838f733764a4d992034e83fa74ad6: Scheduling MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08): perf score=1.000000
I20260812 06:18:40.396306 11653 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.837s	user 1.794s	sys 0.156s
I20260812 06:18:40.449213 11653 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.001s	sys 0.000s
I20260812 06:18:40.450271 11653 tablet_server.cc:179] TabletServer@127.11.97.65:0 shutting down...
I20260812 06:18:40.492327 11811 maintenance_manager.cc:643] P aab838f733764a4d992034e83fa74ad6: MajorDeltaCompactionOp(beff0c1bc50747a990e3f4ca59efcc08) complete. Timing: real 0.126s	user 0.099s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1051,"lbm_read_time_us":9320,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25941,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:18:40.492972 11653 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:40.493500 11653 tablet_replica.cc:333] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6: stopping tablet replica
I20260812 06:18:40.493773 11653 raft_consensus.cc:2243] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.494016 11653 raft_consensus.cc:2272] T beff0c1bc50747a990e3f4ca59efcc08 P aab838f733764a4d992034e83fa74ad6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.519465 11653 tablet_server.cc:196] TabletServer@127.11.97.65:0 shutdown complete.
I20260812 06:18:40.538178 11653 master.cc:562] Master@127.11.97.126:46777 shutting down...
I20260812 06:18:40.542120 11653 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.542285 11653 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.542340 11653 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9113faea3eb64b2b9d3f558883fb458f: stopping tablet replica
I20260812 06:18:40.554541 11653 master.cc:584] Master@127.11.97.126:46777 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5356 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:40.643244 11653 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.97.126:34677
I20260812 06:18:40.643581 11653 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.645879 11963 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:18:40.645925 11653 server_base.cc:1061] running on GCE node
W20260812 06:18:40.645994 11967 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:18:40.646025 11965 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:18:40.646281 11653 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.646323 11653 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:18:40.646338 11653 hybrid_clock.cc:648] HybridClock initialized: now 1786515520646338 us; error 0 us; skew 500 ppm
I20260812 06:18:40.647182 11653 webserver.cc:533] Webserver started at http://127.11.97.126:42933/ using document root <none> and password file <none>
I20260812 06:18:40.647353 11653 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.647399 11653 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.647500 11653 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.647912 11653 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/master-0-root/instance:
uuid: "0c08d2163d2c4b48b51907f19f588497"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-39l8"
I20260812 06:18:40.649365 11653 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:40.650245 11974 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:18:40.650486 11653 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.650584 11653 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/master-0-root
uuid: "0c08d2163d2c4b48b51907f19f588497"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-39l8"
I20260812 06:18:40.650672 11653 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-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:18:40.670887 11653 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.671283 11653 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.675583 11653 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.126:34677
I20260812 06:18:40.680485 12063 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:18:40.682650 12062 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.126:34677 every 8 connection(s)
I20260812 06:18:40.683606 12063 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497: Bootstrap starting.
I20260812 06:18:40.684386 12063 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.685346 12063 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497: No bootstrap required, opened a new log
I20260812 06:18:40.685758 12063 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER }
I20260812 06:18:40.685846 12063 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.685868 12063 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0c08d2163d2c4b48b51907f19f588497, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.686026 12063 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [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: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER }
I20260812 06:18:40.686100 12063 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.686122 12063 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.686175 12063 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.686935 12063 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER }
I20260812 06:18:40.687081 12063 leader_election.cc:304] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [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: 0c08d2163d2c4b48b51907f19f588497; no voters: 
I20260812 06:18:40.687294 12063 leader_election.cc:290] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.687436 12074 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.687661 12074 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 1 LEADER]: Becoming Leader. State: Replica: 0c08d2163d2c4b48b51907f19f588497, State: Running, Role: LEADER
I20260812 06:18:40.687736 12063 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:40.687816 12074 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [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: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER }
I20260812 06:18:40.688274 12076 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0c08d2163d2c4b48b51907f19f588497" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER } }
I20260812 06:18:40.688380 12076 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.688292 12077 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0c08d2163d2c4b48b51907f19f588497. Latest consensus state: current_term: 1 leader_uuid: "0c08d2163d2c4b48b51907f19f588497" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c08d2163d2c4b48b51907f19f588497" member_type: VOTER } }
I20260812 06:18:40.688577 12077 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.688710 12084 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:40.689535 12084 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:40.689723 11653 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:40.691385 12084 catalog_manager.cc:1383] Generated new cluster ID: f643658724a44607b66debb4b1f80b6c
I20260812 06:18:40.691442 12084 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:40.704414 12084 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:40.704978 12084 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:40.712692 12084 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497: Generated new TSK 0
I20260812 06:18:40.712867 12084 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:40.721994 11653 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.724054 12112 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:18:40.724109 12114 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:18:40.724125 12111 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:18:40.724316 11653 server_base.cc:1061] running on GCE node
I20260812 06:18:40.724526 11653 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.724597 11653 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:18:40.724624 11653 hybrid_clock.cc:648] HybridClock initialized: now 1786515520724624 us; error 0 us; skew 500 ppm
I20260812 06:18:40.725472 11653 webserver.cc:533] Webserver started at http://127.11.97.65:36195/ using document root <none> and password file <none>
I20260812 06:18:40.725667 11653 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.725754 11653 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.725852 11653 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.726267 11653 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/instance:
uuid: "ce120553c93c49e4829594b6cbbce834"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-39l8"
I20260812 06:18:40.727833 11653 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:40.728978 12124 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:18:40.729206 11653 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:40.729302 11653 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root
uuid: "ce120553c93c49e4829594b6cbbce834"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-39l8"
I20260812 06:18:40.729394 11653 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-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:18:40.741145 11653 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.741524 11653 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.741839 11653 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:40.742301 11653 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:40.742363 11653 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.742424 11653 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:40.742482 11653 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.746923 11653 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.65:43145
I20260812 06:18:40.749018 12228 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.65:43145 every 8 connection(s)
I20260812 06:18:40.756981 12231 heartbeater.cc:344] Connected to a master server at 127.11.97.126:34677
I20260812 06:18:40.757148 12231 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:40.757402 12231 heartbeater.cc:507] Master 127.11.97.126:34677 requested a full tablet report, sending...
I20260812 06:18:40.758075 12005 ts_manager.cc:194] Registered new tserver with Master: ce120553c93c49e4829594b6cbbce834 (127.11.97.65:43145)
I20260812 06:18:40.758750 11653 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01114778s
I20260812 06:18:40.758888 12005 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59826
I20260812 06:18:40.765571 12005 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59834:
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:18:40.774098 12166 tablet_service.cc:1511] Processing CreateTablet for tablet b6e6f524050942c68ccacacb39a8db3b (DEFAULT_TABLE table=heavy-update-compaction-test [id=d8739e795ae54065acdbf6b71bc52e11]), partition=
I20260812 06:18:40.774394 12166 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b6e6f524050942c68ccacacb39a8db3b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:40.776417 12252 tablet_bootstrap.cc:492] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Bootstrap starting.
I20260812 06:18:40.777330 12252 tablet_bootstrap.cc:654] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.778368 12252 tablet_bootstrap.cc:492] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: No bootstrap required, opened a new log
I20260812 06:18:40.778440 12252 ts_tablet_manager.cc:1403] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:40.778805 12252 raft_consensus.cc:359] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce120553c93c49e4829594b6cbbce834" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 43145 } }
I20260812 06:18:40.778893 12252 raft_consensus.cc:385] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.778915 12252 raft_consensus.cc:740] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ce120553c93c49e4829594b6cbbce834, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.779058 12252 consensus_queue.cc:260] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [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: "ce120553c93c49e4829594b6cbbce834" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 43145 } }
I20260812 06:18:40.779147 12252 raft_consensus.cc:399] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.779172 12252 raft_consensus.cc:493] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.779235 12252 raft_consensus.cc:3060] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.780194 12252 raft_consensus.cc:515] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce120553c93c49e4829594b6cbbce834" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 43145 } }
I20260812 06:18:40.780310 12252 leader_election.cc:304] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [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: ce120553c93c49e4829594b6cbbce834; no voters: 
I20260812 06:18:40.780458 12252 leader_election.cc:290] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.780591 12254 raft_consensus.cc:2804] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.780795 12252 ts_tablet_manager.cc:1434] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:40.780825 12231 heartbeater.cc:499] Master 127.11.97.126:34677 was elected leader, sending a full tablet report...
I20260812 06:18:40.780830 12254 raft_consensus.cc:697] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 1 LEADER]: Becoming Leader. State: Replica: ce120553c93c49e4829594b6cbbce834, State: Running, Role: LEADER
I20260812 06:18:40.781109 12254 consensus_queue.cc:237] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [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: "ce120553c93c49e4829594b6cbbce834" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 43145 } }
I20260812 06:18:40.782480 12005 catalog_manager.cc:5719] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 reported cstate change: term changed from 0 to 1, leader changed from <none> to ce120553c93c49e4829594b6cbbce834 (127.11.97.65). New cstate: current_term: 1 leader_uuid: "ce120553c93c49e4829594b6cbbce834" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce120553c93c49e4829594b6cbbce834" member_type: VOTER last_known_addr { host: "127.11.97.65" port: 43145 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:40.841761 11653 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.008s
I20260812 06:18:40.999496 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b): perf score=19.054940
I20260812 06:18:41.151626 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.152s	user 0.115s	sys 0.036s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":795,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39440,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1664,"update_count":1500}
I20260812 06:18:41.152396 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling LogGCOp(b6e6f524050942c68ccacacb39a8db3b): free 20743880 bytes of WAL
I20260812 06:18:41.152621 12130 log_reader.cc:385] T b6e6f524050942c68ccacacb39a8db3b: removed 2 log segments from log reader
I20260812 06:18:41.152679 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000001 (ops 1-6)
I20260812 06:18:41.152719 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000002 (ops 7-11)
I20260812 06:18:41.157725 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: LogGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:41.158059 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b): 16821647 bytes on disk
I20260812 06:18:41.158443 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:41.158905 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:41.182369 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.023s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.182911 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:41.196496 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5026,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:41.197412 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:41.364106 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.166s	user 0.109s	sys 0.053s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405551,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":460,"lbm_read_time_us":11413,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28778,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":326,"threads_started":5,"update_count":2450}
I20260812 06:18:41.364897 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:41.422580 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.057s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21991,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:41.423058 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:41.433419 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.433838 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:41.605729 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.172s	user 0.099s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1118,"lbm_read_time_us":12814,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27084,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:41.606384 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:41.664121 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.057s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19852,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.664640 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:41.677122 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.677896 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:41.848657 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.171s	user 0.134s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":12971,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28696,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:18:41.849370 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:41.901357 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.052s	user 0.021s	sys 0.029s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23075,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.901890 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:41.916893 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.917524 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:42.094419 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.177s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":13526,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29487,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:42.095060 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:42.152040 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.057s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.152561 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:42.169603 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.170106 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:42.348651 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.178s	user 0.106s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":11963,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27816,"lbm_writes_lt_1ms":543,"mutex_wait_us":156,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:18:42.349287 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=15.087375
I20260812 06:18:42.418520 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.069s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21224,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:42.419107 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=6.157687
I20260812 06:18:42.439636 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.020s	user 0.011s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8325,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:42.440160 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:42.474290 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.034s	user 0.016s	sys 0.008s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1744,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1603,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:42.474946 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling LogGCOp(b6e6f524050942c68ccacacb39a8db3b): free 124257239 bytes of WAL
I20260812 06:18:42.475171 12130 log_reader.cc:385] T b6e6f524050942c68ccacacb39a8db3b: removed 12 log segments from log reader
I20260812 06:18:42.475232 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000003 (ops 12-16)
I20260812 06:18:42.475288 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000004 (ops 17-21)
I20260812 06:18:42.475343 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000005 (ops 22-26)
I20260812 06:18:42.475385 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000006 (ops 27-31)
I20260812 06:18:42.475421 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000007 (ops 32-36)
I20260812 06:18:42.475464 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000008 (ops 37-41)
I20260812 06:18:42.475500 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000009 (ops 42-46)
I20260812 06:18:42.475538 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000010 (ops 47-51)
I20260812 06:18:42.475574 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000011 (ops 52-56)
I20260812 06:18:42.475610 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000012 (ops 57-61)
I20260812 06:18:42.475646 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000013 (ops 62-66)
I20260812 06:18:42.475683 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000014 (ops 67-70)
I20260812 06:18:42.500895 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: LogGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:42.501348 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:42.516834 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.517261 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b): 472 bytes on disk
I20260812 06:18:42.517633 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.518067 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:42.528080 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3796,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.528637 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:42.769136 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.240s	user 0.176s	sys 0.065s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123157,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":275,"lbm_read_time_us":18021,"lbm_reads_lt_1ms":874,"lbm_write_time_us":41426,"lbm_writes_lt_1ms":843,"mutex_wait_us":23,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":90,"threads_started":1,"update_count":4000}
I20260812 06:18:42.769883 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=18.063937
I20260812 06:18:42.834566 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.064s	user 0.040s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26842,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:42.835141 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=3.181125
I20260812 06:18:42.851161 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6282,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:42.851748 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:42.866366 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5674,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.867064 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:43.054255 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.187s	user 0.142s	sys 0.045s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020618,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":605,"lbm_read_time_us":13588,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38527,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":3500}
I20260812 06:18:43.055245 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=15.087375
I20260812 06:18:43.103256 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16697071,"delete_count":0,"lbm_write_time_us":20942,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2035}
I20260812 06:18:43.103946 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.116596 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4862,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:43.117038 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:43.278541 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.161s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815678,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":101,"lbm_read_time_us":9753,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32245,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:43.279129 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:43.332270 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.053s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22943,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.332780 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.345579 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.346004 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:43.514448 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.168s	user 0.120s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":12089,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26787,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":50560,"update_count":2500}
I20260812 06:18:43.515239 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:43.570956 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.055s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24257,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.571472 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.586573 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5609,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.587080 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:43.767273 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.180s	user 0.090s	sys 0.090s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":11162,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31756,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:43.767855 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:43.821812 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.054s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22515,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.822362 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.851744 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.029s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.852206 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.863139 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.863691 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:43.895342 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":168,"dirs.run_wall_time_us":1320,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1470,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:43.896100 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling LogGCOp(b6e6f524050942c68ccacacb39a8db3b): free 121459504 bytes of WAL
I20260812 06:18:43.896302 12130 log_reader.cc:385] T b6e6f524050942c68ccacacb39a8db3b: removed 12 log segments from log reader
I20260812 06:18:43.896351 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000015 (ops 71-75)
I20260812 06:18:43.896389 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000016 (ops 76-80)
I20260812 06:18:43.896420 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000017 (ops 81-85)
I20260812 06:18:43.896442 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000018 (ops 86-90)
I20260812 06:18:43.896464 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000019 (ops 91-95)
I20260812 06:18:43.896498 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000020 (ops 96-100)
I20260812 06:18:43.896540 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000021 (ops 101-105)
I20260812 06:18:43.896564 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000022 (ops 106-110)
I20260812 06:18:43.896584 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000023 (ops 111-115)
I20260812 06:18:43.896612 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000024 (ops 116-120)
I20260812 06:18:43.896644 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000025 (ops 121-125)
I20260812 06:18:43.896679 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000026 (ops 126-130)
I20260812 06:18:43.927868 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: LogGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:43.928287 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b): 472 bytes on disk
I20260812 06:18:43.928718 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b) 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:18:43.929224 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.953763 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.024s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.954299 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:43.968830 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.969365 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:44.201886 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.232s	user 0.148s	sys 0.084s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":722,"lbm_read_time_us":19552,"lbm_reads_lt_1ms":875,"lbm_write_time_us":42579,"lbm_writes_lt_1ms":843,"mutex_wait_us":68,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":77,"threads_started":1,"update_count":4000}
I20260812 06:18:44.202611 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=18.063937
I20260812 06:18:44.274518 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.072s	user 0.032s	sys 0.036s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29906,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:44.275215 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=3.181125
I20260812 06:18:44.297340 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.022s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6422,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:44.297864 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:44.307914 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3683,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:44.308418 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:44.489188 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.181s	user 0.145s	sys 0.034s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020619,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":269,"lbm_read_time_us":12310,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39484,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":3500}
I20260812 06:18:44.490012 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:44.537489 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.047s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21122,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.538070 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:44.553984 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.554458 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:44.693492 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.139s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":9128,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26657,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:18:44.694140 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:44.743839 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.050s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20148,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.744445 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:44.760419 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.761036 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:44.915854 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.155s	user 0.119s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1018,"lbm_read_time_us":10927,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30388,"lbm_writes_lt_1ms":543,"mutex_wait_us":370,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:44.916742 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=10.126437
I20260812 06:18:44.952570 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15321,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.953174 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:44.968680 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.969158 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:45.126384 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.157s	user 0.106s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":10165,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24121,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:18:45.127063 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=14.095187
I20260812 06:18:45.190871 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.064s	user 0.026s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20857,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.191468 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=2.188937
I20260812 06:18:45.207367 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.207890 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:45.242038 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushMRSOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.034s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":288,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1531,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:45.243024 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:45.437251 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.194s	user 0.133s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":13777,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31529,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:45.438041 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling LogGCOp(b6e6f524050942c68ccacacb39a8db3b): free 124257501 bytes of WAL
I20260812 06:18:45.438342 12130 log_reader.cc:385] T b6e6f524050942c68ccacacb39a8db3b: removed 12 log segments from log reader
I20260812 06:18:45.438418 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000027 (ops 131-135)
I20260812 06:18:45.438516 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000028 (ops 136-140)
I20260812 06:18:45.438589 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000029 (ops 141-145)
I20260812 06:18:45.438663 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000030 (ops 146-150)
I20260812 06:18:45.438747 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000031 (ops 151-155)
I20260812 06:18:45.438822 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000032 (ops 156-160)
I20260812 06:18:45.438861 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000033 (ops 161-165)
I20260812 06:18:45.438907 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000034 (ops 166-170)
I20260812 06:18:45.438951 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000035 (ops 171-174)
I20260812 06:18:45.438994 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000036 (ops 175-179)
I20260812 06:18:45.439038 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000037 (ops 180-184)
I20260812 06:18:45.439092 12130 log.cc:1079] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: Deleting log segment in path: /tmp/dist-test-taskhAZOn7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515515276839-11653-0/minicluster-data/ts-0-root/wals/b6e6f524050942c68ccacacb39a8db3b/wal-000000038 (ops 185-189)
I20260812 06:18:45.465776 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: LogGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:45.466233 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b): 448 bytes on disk
I20260812 06:18:45.466915 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: UndoDeltaBlockGCOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.467716 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=15.087375
I20260812 06:18:45.532567 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.065s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21148,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:45.533104 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b): perf score=6.157687
I20260812 06:18:45.551412 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: FlushDeltaMemStoresOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":7882,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:45.552060 12237 maintenance_manager.cc:419] P ce120553c93c49e4829594b6cbbce834: Scheduling MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b): perf score=1.000000
I20260812 06:18:45.590984 11653 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.749s	user 1.823s	sys 0.170s
I20260812 06:18:45.673527 11653 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.000s	sys 0.000s
I20260812 06:18:45.674044 11653 tablet_server.cc:179] TabletServer@127.11.97.65:0 shutting down...
I20260812 06:18:45.735342 12130 maintenance_manager.cc:643] P ce120553c93c49e4829594b6cbbce834: MajorDeltaCompactionOp(b6e6f524050942c68ccacacb39a8db3b) complete. Timing: real 0.183s	user 0.118s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":16628,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29900,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:18:45.736045 11653 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:45.736299 11653 tablet_replica.cc:333] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834: stopping tablet replica
I20260812 06:18:45.736454 11653 raft_consensus.cc:2243] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:45.736629 11653 raft_consensus.cc:2272] T b6e6f524050942c68ccacacb39a8db3b P ce120553c93c49e4829594b6cbbce834 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:45.751360 11653 tablet_server.cc:196] TabletServer@127.11.97.65:0 shutdown complete.
I20260812 06:18:45.788439 11653 master.cc:562] Master@127.11.97.126:34677 shutting down...
I20260812 06:18:45.792342 11653 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:45.792518 11653 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:45.792570 11653 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0c08d2163d2c4b48b51907f19f588497: stopping tablet replica
I20260812 06:18:45.804889 11653 master.cc:584] Master@127.11.97.126:34677 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5248 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10606 ms total)

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