[==========] 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:16:23.406991 27652 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.1.62:34925
I20260812 06:16:23.408039 27652 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:16:23.408677 27652 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.415320 27659 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:16:23.415472 27657 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:16:23.415488 27652 server_base.cc:1061] running on GCE node
W20260812 06:16:23.415776 27662 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:16:23.416325 27652 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.416419 27652 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:16:23.416453 27652 hybrid_clock.cc:648] HybridClock initialized: now 1786515383416451 us; error 0 us; skew 500 ppm
I20260812 06:16:23.418265 27652 webserver.cc:533] Webserver started at http://127.27.1.62:40191/ using document root <none> and password file <none>
I20260812 06:16:23.418778 27652 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.418834 27652 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.419021 27652 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.420617 27652 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/master-0-root/instance:
uuid: "6332726592ff4fb99aa1ac5e30ebd477"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-0kls"
I20260812 06:16:23.424036 27652 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:16:23.426054 27667 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:16:23.427029 27652 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:23.427125 27652 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/master-0-root
uuid: "6332726592ff4fb99aa1ac5e30ebd477"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-0kls"
I20260812 06:16:23.427253 27652 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-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:16:23.454357 27652 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.455101 27652 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:16:23.455302 27652 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.463379 27652 rpc_server.cc:307] RPC server started. Bound to: 127.27.1.62:34925
I20260812 06:16:23.463456 27727 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.1.62:34925 every 8 connection(s)
I20260812 06:16:23.465724 27728 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:16:23.471313 27728 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: Bootstrap starting.
I20260812 06:16:23.473809 27728 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.474807 27728 log.cc:826] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:23.476718 27728 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: No bootstrap required, opened a new log
I20260812 06:16:23.479782 27728 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER }
I20260812 06:16:23.479952 27728 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.480052 27728 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6332726592ff4fb99aa1ac5e30ebd477, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.480684 27728 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [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: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER }
I20260812 06:16:23.480854 27728 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.480927 27728 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.481107 27728 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.481988 27728 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER }
I20260812 06:16:23.482460 27728 leader_election.cc:304] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [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: 6332726592ff4fb99aa1ac5e30ebd477; no voters: 
I20260812 06:16:23.482805 27728 leader_election.cc:290] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.482947 27731 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.483212 27731 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 1 LEADER]: Becoming Leader. State: Replica: 6332726592ff4fb99aa1ac5e30ebd477, State: Running, Role: LEADER
I20260812 06:16:23.483695 27731 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [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: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER }
I20260812 06:16:23.483954 27728 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:23.485500 27734 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6332726592ff4fb99aa1ac5e30ebd477. Latest consensus state: current_term: 1 leader_uuid: "6332726592ff4fb99aa1ac5e30ebd477" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER } }
I20260812 06:16:23.485607 27734 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.485843 27732 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6332726592ff4fb99aa1ac5e30ebd477" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6332726592ff4fb99aa1ac5e30ebd477" member_type: VOTER } }
I20260812 06:16:23.485929 27732 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.486264 27743 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:23.486590 27652 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:23.488803 27743 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:23.494001 27743 catalog_manager.cc:1383] Generated new cluster ID: 3abe7e2838c74c09aae74ccc7f092f2b
I20260812 06:16:23.494087 27743 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:23.502323 27743 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:23.503646 27743 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:23.519125 27743 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: Generated new TSK 0
I20260812 06:16:23.519989 27743 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.551808 27652 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.555759 27756 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:16:23.555833 27754 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:16:23.555811 27753 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:16:23.556044 27652 server_base.cc:1061] running on GCE node
I20260812 06:16:23.556206 27652 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.556252 27652 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:16:23.556275 27652 hybrid_clock.cc:648] HybridClock initialized: now 1786515383556275 us; error 0 us; skew 500 ppm
I20260812 06:16:23.557219 27652 webserver.cc:533] Webserver started at http://127.27.1.1:37635/ using document root <none> and password file <none>
I20260812 06:16:23.557391 27652 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.557453 27652 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.557533 27652 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.558027 27652 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/instance:
uuid: "085bc509fcd54db8afd3a2a59744740b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-0kls"
I20260812 06:16:23.559940 27652 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:23.561141 27762 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:16:23.561445 27652 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.561524 27652 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root
uuid: "085bc509fcd54db8afd3a2a59744740b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-0kls"
I20260812 06:16:23.561589 27652 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-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:16:23.579742 27652 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.580502 27652 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.581081 27652 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.582211 27652 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.582280 27652 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.582338 27652 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.582361 27652 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.592029 27652 rpc_server.cc:307] RPC server started. Bound to: 127.27.1.1:33499
I20260812 06:16:23.592108 27830 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.1.1:33499 every 8 connection(s)
I20260812 06:16:23.610157 27831 heartbeater.cc:344] Connected to a master server at 127.27.1.62:34925
I20260812 06:16:23.610479 27831 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.611024 27831 heartbeater.cc:507] Master 127.27.1.62:34925 requested a full tablet report, sending...
I20260812 06:16:23.612597 27687 ts_manager.cc:194] Registered new tserver with Master: 085bc509fcd54db8afd3a2a59744740b (127.27.1.1:33499)
I20260812 06:16:23.612771 27652 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020095608s
I20260812 06:16:23.614387 27687 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41944
I20260812 06:16:23.624107 27687 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41958:
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:16:23.638497 27792 tablet_service.cc:1511] Processing CreateTablet for tablet 7f66f153007e4ae29985860e99cfeeba (DEFAULT_TABLE table=heavy-update-compaction-test [id=6658a5be09d34f06873730f1868e6c0c]), partition=
I20260812 06:16:23.638981 27792 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7f66f153007e4ae29985860e99cfeeba. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.642025 27845 tablet_bootstrap.cc:492] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Bootstrap starting.
I20260812 06:16:23.643529 27845 tablet_bootstrap.cc:654] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.644929 27845 tablet_bootstrap.cc:492] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: No bootstrap required, opened a new log
I20260812 06:16:23.645042 27845 ts_tablet_manager.cc:1403] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:23.645557 27845 raft_consensus.cc:359] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "085bc509fcd54db8afd3a2a59744740b" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 33499 } }
I20260812 06:16:23.645712 27845 raft_consensus.cc:385] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.645751 27845 raft_consensus.cc:740] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 085bc509fcd54db8afd3a2a59744740b, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.645944 27845 consensus_queue.cc:260] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [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: "085bc509fcd54db8afd3a2a59744740b" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 33499 } }
I20260812 06:16:23.646052 27845 raft_consensus.cc:399] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.646092 27845 raft_consensus.cc:493] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.646142 27845 raft_consensus.cc:3060] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.647153 27845 raft_consensus.cc:515] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "085bc509fcd54db8afd3a2a59744740b" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 33499 } }
I20260812 06:16:23.647301 27845 leader_election.cc:304] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [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: 085bc509fcd54db8afd3a2a59744740b; no voters: 
I20260812 06:16:23.647526 27845 leader_election.cc:290] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.647675 27847 raft_consensus.cc:2804] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.647936 27847 raft_consensus.cc:697] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 1 LEADER]: Becoming Leader. State: Replica: 085bc509fcd54db8afd3a2a59744740b, State: Running, Role: LEADER
I20260812 06:16:23.647934 27845 ts_tablet_manager.cc:1434] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:23.648137 27847 consensus_queue.cc:237] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [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: "085bc509fcd54db8afd3a2a59744740b" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 33499 } }
I20260812 06:16:23.648480 27831 heartbeater.cc:499] Master 127.27.1.62:34925 was elected leader, sending a full tablet report...
I20260812 06:16:23.651177 27687 catalog_manager.cc:5719] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b reported cstate change: term changed from 0 to 1, leader changed from <none> to 085bc509fcd54db8afd3a2a59744740b (127.27.1.1). New cstate: current_term: 1 leader_uuid: "085bc509fcd54db8afd3a2a59744740b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "085bc509fcd54db8afd3a2a59744740b" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 33499 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.728032 27652 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.026s	sys 0.011s
I20260812 06:16:23.844461 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushMRSOp(7f66f153007e4ae29985860e99cfeeba): perf score=15.086190
I20260812 06:16:23.969069 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushMRSOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.124s	user 0.089s	sys 0.032s Metrics: {"bytes_written":8615324,"cfile_init":1,"compiler_manager_pool.queue_time_us":758,"delete_count":0,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1210,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":27140,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":143,"threads_started":1,"update_count":1050}
I20260812 06:16:23.970211 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling LogGCOp(7f66f153007e4ae29985860e99cfeeba): free 11976772 bytes of WAL
I20260812 06:16:23.970536 27768 log_reader.cc:385] T 7f66f153007e4ae29985860e99cfeeba: removed 1 log segments from log reader
I20260812 06:16:23.970616 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000001 (ops 1-6)
I20260812 06:16:23.973438 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: LogGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:23.973842 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:23.987015 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4628,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:23.987494 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba): 12308958 bytes on disk
I20260812 06:16:23.988137 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:16:23.988924 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:24.113302 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.124s	user 0.108s	sys 0.013s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528892,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":8650,"lbm_reads_lt_1ms":360,"lbm_write_time_us":22278,"lbm_writes_lt_1ms":343,"mutex_wait_us":72,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":338,"threads_started":5,"update_count":1500}
I20260812 06:16:24.114096 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=7.149875
I20260812 06:16:24.141047 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.027s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11912,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:24.141571 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.158720 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6735,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.159190 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:24.265899 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.107s	user 0.088s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":5906,"lbm_reads_lt_1ms":368,"lbm_write_time_us":19537,"lbm_writes_lt_1ms":343,"mutex_wait_us":57,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:16:24.266619 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:24.311425 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.045s	user 0.011s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14649,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.311942 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.322906 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4057,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.323565 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:24.451612 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.128s	user 0.110s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":8320,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25255,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:16:24.452378 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:24.500787 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.048s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18337,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.501274 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.513577 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.514159 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:24.653362 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.139s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":9130,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29648,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2000}
I20260812 06:16:24.654392 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:24.692672 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.038s	user 0.030s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17157,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.693197 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.712924 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.020s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.713618 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:24.849661 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.136s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1079,"lbm_read_time_us":8751,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28260,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:24.850544 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=11.118625
I20260812 06:16:24.899253 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.048s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18282,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:24.899976 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.929006 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.029s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5466,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.929522 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:24.940026 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.940527 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:25.118927 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.178s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1032,"lbm_read_time_us":12085,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31042,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:16:25.119638 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:25.184005 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.064s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25346,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.184715 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:25.204272 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.019s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.204780 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushMRSOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:25.238982 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushMRSOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.034s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1559,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1985,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:25.239857 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling LogGCOp(7f66f153007e4ae29985860e99cfeeba): free 121006367 bytes of WAL
I20260812 06:16:25.240093 27768 log_reader.cc:385] T 7f66f153007e4ae29985860e99cfeeba: removed 12 log segments from log reader
I20260812 06:16:25.240134 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000002 (ops 7-11)
I20260812 06:16:25.240164 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000003 (ops 12-16)
I20260812 06:16:25.240219 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000004 (ops 17-21)
I20260812 06:16:25.240264 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000005 (ops 22-26)
I20260812 06:16:25.240327 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000006 (ops 27-31)
I20260812 06:16:25.240365 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000007 (ops 32-36)
I20260812 06:16:25.240412 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000008 (ops 37-41)
I20260812 06:16:25.240453 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000009 (ops 42-46)
I20260812 06:16:25.240492 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000010 (ops 47-51)
I20260812 06:16:25.240532 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000011 (ops 52-56)
I20260812 06:16:25.240572 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000012 (ops 57-60)
I20260812 06:16:25.240612 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000013 (ops 61-65)
I20260812 06:16:25.265897 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: LogGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:25.266321 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:25.288638 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.022s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.289106 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:25.299255 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3974,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.299790 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba): 447 bytes on disk
I20260812 06:16:25.300233 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba) 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:16:25.300750 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:25.530130 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.229s	user 0.147s	sys 0.081s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938785,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":264,"lbm_read_time_us":15965,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40729,"lbm_writes_lt_1ms":743,"mutex_wait_us":57,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":85504,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:16:25.532546 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:25.576201 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.043s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19547,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.576786 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:25.590691 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.591130 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:25.763871 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.173s	user 0.108s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":11521,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29784,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:16:25.764552 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:25.822738 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.058s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21003,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.823330 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:25.834131 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.834561 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.010682 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.176s	user 0.105s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1865,"lbm_read_time_us":12011,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30930,"lbm_writes_lt_1ms":543,"mutex_wait_us":674,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.011548 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:26.071585 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.060s	user 0.025s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21758,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.072180 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:26.083216 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.083686 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.258015 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.174s	user 0.104s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2557,"lbm_read_time_us":13556,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28603,"lbm_writes_lt_1ms":543,"mutex_wait_us":2123,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:16:26.258903 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:26.297016 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.038s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16424,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:26.297547 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:26.311638 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.312256 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.444222 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":607,"lbm_read_time_us":8524,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23696,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.444887 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:26.484802 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.040s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16862,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:26.485356 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:26.498519 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.499125 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.627828 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.129s	user 0.084s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":9021,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26213,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:16:26.630429 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=10.126437
I20260812 06:16:26.675151 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.044s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18103,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:26.675613 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:26.686441 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.687186 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushMRSOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.721124 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushMRSOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1376,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1949,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:26.721915 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling LogGCOp(7f66f153007e4ae29985860e99cfeeba): free 120553433 bytes of WAL
I20260812 06:16:26.722157 27768 log_reader.cc:385] T 7f66f153007e4ae29985860e99cfeeba: removed 12 log segments from log reader
I20260812 06:16:26.722201 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000014 (ops 66-70)
I20260812 06:16:26.722231 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000015 (ops 71-75)
I20260812 06:16:26.722278 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000016 (ops 76-80)
I20260812 06:16:26.722321 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000017 (ops 81-85)
I20260812 06:16:26.722348 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000018 (ops 86-90)
I20260812 06:16:26.722398 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000019 (ops 91-94)
I20260812 06:16:26.722441 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000020 (ops 95-99)
I20260812 06:16:26.722478 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000021 (ops 100-104)
I20260812 06:16:26.722509 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000022 (ops 105-108)
I20260812 06:16:26.722543 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000023 (ops 109-113)
I20260812 06:16:26.722577 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000024 (ops 114-118)
I20260812 06:16:26.722616 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000025 (ops 119-123)
I20260812 06:16:26.750115 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: LogGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:26.750788 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=3.181125
I20260812 06:16:26.770962 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.020s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4430855,"delete_count":0,"lbm_write_time_us":6860,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:16:26.771412 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba): 463 bytes on disk
I20260812 06:16:26.771832 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba) 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:16:26.772353 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:26.782047 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3625,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:26.782516 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:26.959640 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.177s	user 0.137s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836371,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":689,"lbm_read_time_us":12422,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37244,"lbm_writes_lt_1ms":643,"mutex_wait_us":334,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:16:26.960423 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:27.012411 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.052s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19680,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.012883 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:27.024423 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.025002 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:27.185084 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.160s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":10823,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32593,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:16:27.185913 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=12.110812
I20260812 06:16:27.224578 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.038s	user 0.013s	sys 0.024s Metrics: {"bytes_written":13497196,"delete_count":0,"lbm_write_time_us":16336,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1645}
I20260812 06:16:27.225173 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.196750
I20260812 06:16:27.240396 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:16:27.240907 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:27.385876 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.145s	user 0.094s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631289,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":597,"lbm_read_time_us":9509,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23348,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:16:27.388957 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:27.445389 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.056s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26378,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.446045 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:27.469529 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.023s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.470109 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:27.640357 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.170s	user 0.109s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1054,"lbm_read_time_us":11354,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27897,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:16:27.640985 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:27.694283 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.053s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25457,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.695217 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:27.709862 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.014s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.710374 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:27.897907 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.187s	user 0.131s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":10000,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31018,"lbm_writes_lt_1ms":543,"mutex_wait_us":112,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:16:27.898792 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:27.953256 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.054s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25642,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.953879 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:27.968163 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.968844 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:28.133409 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.164s	user 0.123s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":951,"lbm_read_time_us":9176,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30747,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:16:28.134183 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=14.095187
I20260812 06:16:28.192505 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.058s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26612,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.193117 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:28.206699 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.207172 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushMRSOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:28.239120 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushMRSOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.032s	user 0.024s	sys 0.006s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1364,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1713,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:28.239809 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling LogGCOp(7f66f153007e4ae29985860e99cfeeba): free 128414424 bytes of WAL
I20260812 06:16:28.240034 27768 log_reader.cc:385] T 7f66f153007e4ae29985860e99cfeeba: removed 12 log segments from log reader
I20260812 06:16:28.240101 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000026 (ops 124-128)
I20260812 06:16:28.240152 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000027 (ops 129-133)
I20260812 06:16:28.240208 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000028 (ops 134-138)
I20260812 06:16:28.240252 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000029 (ops 139-143)
I20260812 06:16:28.240289 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000030 (ops 144-148)
I20260812 06:16:28.240330 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000031 (ops 149-153)
I20260812 06:16:28.240370 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000032 (ops 154-158)
I20260812 06:16:28.240410 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000033 (ops 159-163)
I20260812 06:16:28.240450 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000034 (ops 164-168)
I20260812 06:16:28.240490 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000035 (ops 169-173)
I20260812 06:16:28.240530 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000036 (ops 174-179)
I20260812 06:16:28.240566 27768 log.cc:1079] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/7f66f153007e4ae29985860e99cfeeba/wal-000000037 (ops 180-184)
I20260812 06:16:28.267148 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: LogGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:28.267670 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba): 482 bytes on disk
I20260812 06:16:28.268309 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: UndoDeltaBlockGCOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.268903 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=6.157687
I20260812 06:16:28.300697 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.032s	user 0.010s	sys 0.019s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9109,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:28.301391 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:28.521226 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.220s	user 0.160s	sys 0.060s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938667,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":184,"lbm_read_time_us":14955,"lbm_reads_lt_1ms":765,"lbm_write_time_us":39148,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:16:28.523949 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=18.063937
I20260812 06:16:28.590538 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.066s	user 0.054s	sys 0.012s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29525,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:28.591078 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba): perf score=2.188937
I20260812 06:16:28.601575 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: FlushDeltaMemStoresOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.602137 27832 maintenance_manager.cc:419] P 085bc509fcd54db8afd3a2a59744740b: Scheduling MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba): perf score=1.000000
I20260812 06:16:28.634084 27652 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.906s	user 1.799s	sys 0.093s
I20260812 06:16:28.722872 27652 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.002s	sys 0.000s
I20260812 06:16:28.723510 27652 tablet_server.cc:179] TabletServer@127.27.1.1:0 shutting down...
I20260812 06:16:28.783522 27768 maintenance_manager.cc:643] P 085bc509fcd54db8afd3a2a59744740b: MajorDeltaCompactionOp(7f66f153007e4ae29985860e99cfeeba) complete. Timing: real 0.181s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836139,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":370,"lbm_read_time_us":14967,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31714,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:16:28.784289 27652 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:28.784724 27652 tablet_replica.cc:333] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b: stopping tablet replica
I20260812 06:16:28.784976 27652 raft_consensus.cc:2243] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.785223 27652 raft_consensus.cc:2272] T 7f66f153007e4ae29985860e99cfeeba P 085bc509fcd54db8afd3a2a59744740b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.802330 27652 tablet_server.cc:196] TabletServer@127.27.1.1:0 shutdown complete.
I20260812 06:16:28.837553 27652 master.cc:562] Master@127.27.1.62:34925 shutting down...
I20260812 06:16:28.841575 27652 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.841848 27652 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.841974 27652 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6332726592ff4fb99aa1ac5e30ebd477: stopping tablet replica
I20260812 06:16:28.854833 27652 master.cc:584] Master@127.27.1.62:34925 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5543 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:28.961277 27652 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.1.62:40307
I20260812 06:16:28.961907 27652 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.963941 27868 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:16:28.964071 27871 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:16:28.964112 27869 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:16:28.964270 27652 server_base.cc:1061] running on GCE node
I20260812 06:16:28.964449 27652 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.964499 27652 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:16:28.964515 27652 hybrid_clock.cc:648] HybridClock initialized: now 1786515388964515 us; error 0 us; skew 500 ppm
I20260812 06:16:28.965427 27652 webserver.cc:533] Webserver started at http://127.27.1.62:39123/ using document root <none> and password file <none>
I20260812 06:16:28.965602 27652 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.965679 27652 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.965767 27652 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.966228 27652 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/master-0-root/instance:
uuid: "6aaf4a0bd74e48668949ed5c64c2d698"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-0kls"
I20260812 06:16:28.967864 27652 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.968981 27877 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:16:28.969296 27652 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.969412 27652 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/master-0-root
uuid: "6aaf4a0bd74e48668949ed5c64c2d698"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-0kls"
I20260812 06:16:28.969506 27652 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-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:16:28.979919 27652 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.980369 27652 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.984972 27652 rpc_server.cc:307] RPC server started. Bound to: 127.27.1.62:40307
I20260812 06:16:28.988732 27938 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:16:28.992916 27937 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.1.62:40307 every 8 connection(s)
I20260812 06:16:28.994160 27938 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698: Bootstrap starting.
I20260812 06:16:28.995213 27938 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.996338 27938 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698: No bootstrap required, opened a new log
I20260812 06:16:28.996762 27938 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER }
I20260812 06:16:28.996870 27938 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.996922 27938 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6aaf4a0bd74e48668949ed5c64c2d698, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.997084 27938 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [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: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER }
I20260812 06:16:28.997187 27938 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.997237 27938 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.997294 27938 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.998040 27938 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER }
I20260812 06:16:28.998209 27938 leader_election.cc:304] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [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: 6aaf4a0bd74e48668949ed5c64c2d698; no voters: 
I20260812 06:16:28.998404 27938 leader_election.cc:290] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.998540 27941 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.998793 27941 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 1 LEADER]: Becoming Leader. State: Replica: 6aaf4a0bd74e48668949ed5c64c2d698, State: Running, Role: LEADER
I20260812 06:16:28.998894 27938 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:28.998929 27941 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [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: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER }
I20260812 06:16:28.999344 27943 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6aaf4a0bd74e48668949ed5c64c2d698. Latest consensus state: current_term: 1 leader_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER } }
I20260812 06:16:28.999440 27943 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.999329 27942 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6aaf4a0bd74e48668949ed5c64c2d698" member_type: VOTER } }
I20260812 06:16:28.999575 27942 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.999805 27946 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:29.000528 27946 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:29.000988 27652 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:29.002558 27946 catalog_manager.cc:1383] Generated new cluster ID: e0b054675af14245bc7dc3479c4175fc
I20260812 06:16:29.002617 27946 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:29.026986 27946 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:29.027586 27946 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:29.032678 27946 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698: Generated new TSK 0
I20260812 06:16:29.032887 27946 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:29.065692 27652 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:29.067988 27963 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:16:29.068034 27652 server_base.cc:1061] running on GCE node
W20260812 06:16:29.068043 27965 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:16:29.068053 27962 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:16:29.068573 27652 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:29.068645 27652 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:16:29.068682 27652 hybrid_clock.cc:648] HybridClock initialized: now 1786515389068682 us; error 0 us; skew 500 ppm
I20260812 06:16:29.069586 27652 webserver.cc:533] Webserver started at http://127.27.1.1:44765/ using document root <none> and password file <none>
I20260812 06:16:29.069823 27652 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:29.069892 27652 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:29.069970 27652 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:29.070396 27652 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/instance:
uuid: "66454e5961a24ceb94acaae028403ebb"
format_stamp: "Formatted at 2026-08-12 06:16:29 on dist-test-slave-0kls"
I20260812 06:16:29.071956 27652 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:29.072892 27972 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:16:29.073179 27652 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:29.073282 27652 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root
uuid: "66454e5961a24ceb94acaae028403ebb"
format_stamp: "Formatted at 2026-08-12 06:16:29 on dist-test-slave-0kls"
I20260812 06:16:29.073376 27652 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-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:16:29.095427 27652 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:29.095901 27652 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:29.096263 27652 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:29.096766 27652 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:29.096830 27652 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:29.096894 27652 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:29.096944 27652 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:29.102388 27652 rpc_server.cc:307] RPC server started. Bound to: 127.27.1.1:34503
I20260812 06:16:29.102481 28044 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.1.1:34503 every 8 connection(s)
I20260812 06:16:29.111948 28045 heartbeater.cc:344] Connected to a master server at 127.27.1.62:40307
I20260812 06:16:29.112083 28045 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:29.112296 28045 heartbeater.cc:507] Master 127.27.1.62:40307 requested a full tablet report, sending...
I20260812 06:16:29.113051 27900 ts_manager.cc:194] Registered new tserver with Master: 66454e5961a24ceb94acaae028403ebb (127.27.1.1:34503)
I20260812 06:16:29.114030 27900 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35152
I20260812 06:16:29.114068 27652 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011158933s
I20260812 06:16:29.121589 27900 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35158:
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:16:29.130687 28001 tablet_service.cc:1511] Processing CreateTablet for tablet 814cb174e45041758d1b0df0088f2330 (DEFAULT_TABLE table=heavy-update-compaction-test [id=17404b0407544e2dacabf08ac79a1351]), partition=
I20260812 06:16:29.130997 28001 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 814cb174e45041758d1b0df0088f2330. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:29.133024 28058 tablet_bootstrap.cc:492] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Bootstrap starting.
I20260812 06:16:29.133949 28058 tablet_bootstrap.cc:654] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:29.135136 28058 tablet_bootstrap.cc:492] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: No bootstrap required, opened a new log
I20260812 06:16:29.135231 28058 ts_tablet_manager.cc:1403] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:16:29.135738 28058 raft_consensus.cc:359] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66454e5961a24ceb94acaae028403ebb" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 34503 } }
I20260812 06:16:29.135896 28058 raft_consensus.cc:385] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:29.135943 28058 raft_consensus.cc:740] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 66454e5961a24ceb94acaae028403ebb, State: Initialized, Role: FOLLOWER
I20260812 06:16:29.136232 28058 consensus_queue.cc:260] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [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: "66454e5961a24ceb94acaae028403ebb" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 34503 } }
I20260812 06:16:29.136363 28058 raft_consensus.cc:399] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:29.136444 28058 raft_consensus.cc:493] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:29.136530 28058 raft_consensus.cc:3060] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:29.137495 28058 raft_consensus.cc:515] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66454e5961a24ceb94acaae028403ebb" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 34503 } }
I20260812 06:16:29.137640 28058 leader_election.cc:304] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [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: 66454e5961a24ceb94acaae028403ebb; no voters: 
I20260812 06:16:29.137916 28058 leader_election.cc:290] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:29.138033 28062 raft_consensus.cc:2804] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:29.138289 28062 raft_consensus.cc:697] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 1 LEADER]: Becoming Leader. State: Replica: 66454e5961a24ceb94acaae028403ebb, State: Running, Role: LEADER
I20260812 06:16:29.138365 28058 ts_tablet_manager.cc:1434] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:29.138366 28045 heartbeater.cc:499] Master 127.27.1.62:40307 was elected leader, sending a full tablet report...
I20260812 06:16:29.138495 28062 consensus_queue.cc:237] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [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: "66454e5961a24ceb94acaae028403ebb" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 34503 } }
I20260812 06:16:29.139974 27900 catalog_manager.cc:5719] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb reported cstate change: term changed from 0 to 1, leader changed from <none> to 66454e5961a24ceb94acaae028403ebb (127.27.1.1). New cstate: current_term: 1 leader_uuid: "66454e5961a24ceb94acaae028403ebb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66454e5961a24ceb94acaae028403ebb" member_type: VOTER last_known_addr { host: "127.27.1.1" port: 34503 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:29.201983 27652 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.011s	sys 0.012s
I20260812 06:16:29.353531 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushMRSOp(814cb174e45041758d1b0df0088f2330): perf score=19.054940
I20260812 06:16:29.515976 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushMRSOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.162s	user 0.113s	sys 0.047s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":976,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39847,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:29.516798 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling LogGCOp(814cb174e45041758d1b0df0088f2330): free 20290830 bytes of WAL
I20260812 06:16:29.517083 27977 log_reader.cc:385] T 814cb174e45041758d1b0df0088f2330: removed 2 log segments from log reader
I20260812 06:16:29.517145 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000001 (ops 1-6)
I20260812 06:16:29.517187 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000002 (ops 7-10)
I20260812 06:16:29.521612 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: LogGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:29.522025 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:29.546420 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.024s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.546906 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:29.557992 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.558440 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330): 16411392 bytes on disk
I20260812 06:16:29.558904 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:29.559304 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:29.750752 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.191s	user 0.144s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774810,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":627,"lbm_read_time_us":12632,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30408,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":360,"threads_started":5,"update_count":2500}
I20260812 06:16:29.751466 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:29.797459 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19485,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.798188 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:29.956651 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.158s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":897,"lbm_read_time_us":11660,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25778,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:16:29.957330 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=11.118625
I20260812 06:16:30.010543 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.053s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22865,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:16:30.011242 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.029004 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.018s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.029557 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.042959 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5092,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.043473 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:30.242026 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.198s	user 0.115s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1272,"lbm_read_time_us":11824,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29711,"lbm_writes_lt_1ms":543,"mutex_wait_us":556,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:16:30.242738 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:30.291159 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21266,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.291666 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.304312 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.304888 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:30.466476 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.161s	user 0.122s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":529,"lbm_read_time_us":11428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29849,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35840,"update_count":2500}
I20260812 06:16:30.467252 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=11.118625
I20260812 06:16:30.503710 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15911,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:30.504415 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.521375 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5570,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.521957 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:30.651878 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.130s	user 0.084s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1034,"lbm_read_time_us":7939,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26222,"lbm_writes_lt_1ms":443,"mutex_wait_us":420,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.652611 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:30.696177 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.043s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15817,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.696859 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.710353 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4658,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.710999 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:30.848615 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.137s	user 0.112s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":9221,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26304,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:16:30.849228 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:30.901604 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.052s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.902287 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:30.913335 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.913990 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushMRSOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:30.945492 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushMRSOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":104,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1479,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1601,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:30.946403 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:31.112149 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.165s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":11780,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24393,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:16:31.112947 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling LogGCOp(814cb174e45041758d1b0df0088f2330): free 125616631 bytes of WAL
I20260812 06:16:31.113232 27977 log_reader.cc:385] T 814cb174e45041758d1b0df0088f2330: removed 13 log segments from log reader
I20260812 06:16:31.113308 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000003 (ops 11-15)
I20260812 06:16:31.113389 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000004 (ops 16-20)
I20260812 06:16:31.113428 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000005 (ops 21-25)
I20260812 06:16:31.113495 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000006 (ops 26-30)
I20260812 06:16:31.113535 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000007 (ops 31-34)
I20260812 06:16:31.113577 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000008 (ops 35-39)
I20260812 06:16:31.113622 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000009 (ops 40-44)
I20260812 06:16:31.113668 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000010 (ops 45-48)
I20260812 06:16:31.113713 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000011 (ops 49-53)
I20260812 06:16:31.113763 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000012 (ops 54-58)
I20260812 06:16:31.113840 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000013 (ops 59-62)
I20260812 06:16:31.113888 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000014 (ops 63-67)
I20260812 06:16:31.113931 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000015 (ops 68-72)
I20260812 06:16:31.144043 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: LogGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:16:31.144708 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:31.194492 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.050s	user 0.016s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21799,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:16:31.195132 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=3.181125
I20260812 06:16:31.216079 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:31.216638 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:31.235633 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.019s	user 0.007s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3723,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.236176 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:31.443696 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.207s	user 0.135s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":375,"lbm_read_time_us":15396,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32788,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:16:31.444451 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:31.507365 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.063s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22681,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.507964 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:31.519217 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.519737 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:31.710124 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.190s	user 0.120s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":109,"lbm_read_time_us":13063,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32535,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:16:31.710976 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=11.118625
I20260812 06:16:31.748047 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.037s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15772,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:31.748684 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:31.763854 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5481,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.764460 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330): 482 bytes on disk
I20260812 06:16:31.764971 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:16:31.765517 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:31.900187 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.135s	user 0.094s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":8956,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26772,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:31.900889 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:31.943347 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.042s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":1500}
I20260812 06:16:31.943953 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:31.959059 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5723,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.960049 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:32.097332 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.137s	user 0.089s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1052,"lbm_read_time_us":8248,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26773,"lbm_writes_lt_1ms":443,"mutex_wait_us":403,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:16:32.098166 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:32.146320 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.048s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16674,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.146903 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:32.158630 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.159395 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:32.305028 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.145s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":993,"lbm_read_time_us":10058,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29130,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:32.306164 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:32.365173 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.059s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16044,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.365942 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:32.378758 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.379271 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:32.536614 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.157s	user 0.109s	sys 0.048s 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":373,"lbm_read_time_us":11911,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25402,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:16:32.537271 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:32.575063 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15075,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.575817 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushMRSOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:32.631108 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushMRSOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.055s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1489,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2672,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:32.631893 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling LogGCOp(814cb174e45041758d1b0df0088f2330): free 120553388 bytes of WAL
I20260812 06:16:32.632159 27977 log_reader.cc:385] T 814cb174e45041758d1b0df0088f2330: removed 12 log segments from log reader
I20260812 06:16:32.632208 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000016 (ops 73-76)
I20260812 06:16:32.632241 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000017 (ops 77-81)
I20260812 06:16:32.632308 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000018 (ops 82-86)
I20260812 06:16:32.632340 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000019 (ops 87-91)
I20260812 06:16:32.632385 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000020 (ops 92-96)
I20260812 06:16:32.632448 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000021 (ops 97-101)
I20260812 06:16:32.632493 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000022 (ops 102-106)
I20260812 06:16:32.632539 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000023 (ops 107-111)
I20260812 06:16:32.632617 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000024 (ops 112-116)
I20260812 06:16:32.632671 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000025 (ops 117-120)
I20260812 06:16:32.632712 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000026 (ops 121-125)
I20260812 06:16:32.632745 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000027 (ops 126-130)
I20260812 06:16:32.660482 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: LogGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.028s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:16:32.661136 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330): 482 bytes on disk
I20260812 06:16:32.662324 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":114,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.662912 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=7.149875
I20260812 06:16:32.700210 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10602,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:32.701074 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling LogGCOp(814cb174e45041758d1b0df0088f2330): free 11564893 bytes of WAL
I20260812 06:16:32.701375 27977 log_reader.cc:385] T 814cb174e45041758d1b0df0088f2330: removed 1 log segments from log reader
I20260812 06:16:32.701427 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000028 (ops 131-134)
I20260812 06:16:32.704319 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: LogGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:32.704861 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:32.717900 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:32.718497 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:32.918218 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.199s	user 0.150s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1798,"lbm_read_time_us":12752,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33453,"lbm_writes_lt_1ms":643,"mutex_wait_us":1461,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:16:32.919159 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:32.984611 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.065s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22870,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.985319 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:33.001010 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5532,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.001717 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:33.179678 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.178s	user 0.121s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":741,"lbm_read_time_us":10723,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28621,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23808,"update_count":2500}
I20260812 06:16:33.180589 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:33.248425 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.068s	user 0.031s	sys 0.033s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25443,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:33.249015 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=3.181125
I20260812 06:16:33.264106 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5513,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:33.264654 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:33.445039 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.180s	user 0.128s	sys 0.050s Metrics: {"cfile_cache_miss":542,"cfile_cache_miss_bytes":25184934,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":396,"lbm_read_time_us":12684,"lbm_reads_lt_1ms":574,"lbm_write_time_us":29670,"lbm_writes_lt_1ms":553,"mutex_wait_us":43,"peak_mem_usage":63526250,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2550}
I20260812 06:16:33.445865 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:33.495865 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.050s	user 0.023s	sys 0.025s Metrics: {"bytes_written":15999661,"delete_count":0,"lbm_write_time_us":21916,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:16:33.496362 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:33.514804 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.018s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.515403 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:33.702373 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.187s	user 0.125s	sys 0.054s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364447,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":9497,"lbm_reads_lt_1ms":554,"lbm_write_time_us":30801,"lbm_writes_lt_1ms":533,"mutex_wait_us":24,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2450}
I20260812 06:16:33.702951 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:33.755277 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.049s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21297,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:33.755779 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:33.773711 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.018s	user 0.001s	sys 0.008s 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:16:33.774269 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:33.788177 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5182,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.788779 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:33.998494 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.209s	user 0.131s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":354,"lbm_read_time_us":12130,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34129,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32000,"update_count":3000}
I20260812 06:16:33.999384 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=14.095187
I20260812 06:16:34.067266 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.068s	user 0.040s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":29612,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.067974 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:34.093240 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.025s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.093986 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:34.110211 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.110975 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushMRSOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:34.152222 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushMRSOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.041s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1744,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1577,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:34.153034 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling LogGCOp(814cb174e45041758d1b0df0088f2330): free 120553636 bytes of WAL
I20260812 06:16:34.153333 27977 log_reader.cc:385] T 814cb174e45041758d1b0df0088f2330: removed 12 log segments from log reader
I20260812 06:16:34.153412 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000029 (ops 135-139)
I20260812 06:16:34.153501 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000030 (ops 140-144)
I20260812 06:16:34.153544 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000031 (ops 145-149)
I20260812 06:16:34.153616 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000032 (ops 150-154)
I20260812 06:16:34.153667 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000033 (ops 155-159)
I20260812 06:16:34.153735 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000034 (ops 160-164)
I20260812 06:16:34.153808 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000035 (ops 165-168)
I20260812 06:16:34.153848 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000036 (ops 169-173)
I20260812 06:16:34.153916 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000037 (ops 174-178)
I20260812 06:16:34.153963 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000038 (ops 179-183)
I20260812 06:16:34.154035 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000039 (ops 184-188)
I20260812 06:16:34.154076 27977 log.cc:1079] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: Deleting log segment in path: /tmp/dist-test-taskQEQRiq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383396271-27652-0/minicluster-data/ts-0-root/wals/814cb174e45041758d1b0df0088f2330/wal-000000040 (ops 189-192)
I20260812 06:16:34.181155 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: LogGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.028s	user 0.006s	sys 0.019s Metrics: {}
I20260812 06:16:34.181713 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330): 463 bytes on disk
I20260812 06:16:34.182430 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: UndoDeltaBlockGCOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.183207 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=3.181125
I20260812 06:16:34.201300 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.018s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:34.201884 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=2.188937
I20260812 06:16:34.212687 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.213457 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330): perf score=1.000000
I20260812 06:16:34.357159 27652 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.155s	user 1.883s	sys 0.216s
I20260812 06:16:34.452834 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: MajorDeltaCompactionOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.239s	user 0.147s	sys 0.092s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":367,"lbm_read_time_us":18472,"lbm_reads_lt_1ms":871,"lbm_write_time_us":39899,"lbm_writes_lt_1ms":843,"mutex_wait_us":61,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":17152,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:16:34.453740 28046 maintenance_manager.cc:419] P 66454e5961a24ceb94acaae028403ebb: Scheduling FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330): perf score=10.126437
I20260812 06:16:34.468221 27652 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.001s	sys 0.000s
I20260812 06:16:34.468791 27652 tablet_server.cc:179] TabletServer@127.27.1.1:0 shutting down...
I20260812 06:16:34.487321 27977 maintenance_manager.cc:643] P 66454e5961a24ceb94acaae028403ebb: FlushDeltaMemStoresOp(814cb174e45041758d1b0df0088f2330) complete. Timing: real 0.033s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14807,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.487986 27652 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:34.488288 27652 tablet_replica.cc:333] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb: stopping tablet replica
I20260812 06:16:34.488431 27652 raft_consensus.cc:2243] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:34.488577 27652 raft_consensus.cc:2272] T 814cb174e45041758d1b0df0088f2330 P 66454e5961a24ceb94acaae028403ebb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:34.492048 27652 tablet_server.cc:196] TabletServer@127.27.1.1:0 shutdown complete.
I20260812 06:16:34.526042 27652 master.cc:562] Master@127.27.1.62:40307 shutting down...
I20260812 06:16:34.530275 27652 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:34.530496 27652 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:34.530578 27652 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6aaf4a0bd74e48668949ed5c64c2d698: stopping tablet replica
I20260812 06:16:34.543253 27652 master.cc:584] Master@127.27.1.62:40307 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5684 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11228 ms total)

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