[==========] 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:20:19.007136  3554 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.120.190:35761
I20260812 06:20:19.008206  3554 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:20:19.008846  3554 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.015923  3566 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:20:19.015889  3561 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:20:19.016010  3554 server_base.cc:1061] running on GCE node
W20260812 06:20:19.016193  3562 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:20:19.016775  3554 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.016888  3554 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:20:19.016920  3554 hybrid_clock.cc:648] HybridClock initialized: now 1786515619016919 us; error 0 us; skew 500 ppm
I20260812 06:20:19.018853  3554 webserver.cc:533] Webserver started at http://127.3.120.190:36265/ using document root <none> and password file <none>
I20260812 06:20:19.019420  3554 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.019497  3554 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.019701  3554 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.021400  3554 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/master-0-root/instance:
uuid: "3a09b4a4d5a2481eab781bf3b028aad2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-gsp7"
I20260812 06:20:19.025111  3554 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.027427  3577 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:20:19.028496  3554 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.028602  3554 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/master-0-root
uuid: "3a09b4a4d5a2481eab781bf3b028aad2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-gsp7"
I20260812 06:20:19.028689  3554 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-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:20:19.068876  3554 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.069577  3554 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:20:19.069725  3554 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.077816  3554 rpc_server.cc:307] RPC server started. Bound to: 127.3.120.190:35761
I20260812 06:20:19.077837  3658 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.120.190:35761 every 8 connection(s)
I20260812 06:20:19.080154  3659 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:20:19.085754  3659 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: Bootstrap starting.
I20260812 06:20:19.088224  3659 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.089202  3659 log.cc:826] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:19.091096  3659 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: No bootstrap required, opened a new log
I20260812 06:20:19.093997  3659 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER }
I20260812 06:20:19.094215  3659 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.094313  3659 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3a09b4a4d5a2481eab781bf3b028aad2, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.094926  3659 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [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: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER }
I20260812 06:20:19.095125  3659 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.095207  3659 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.095355  3659 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.096205  3659 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER }
I20260812 06:20:19.096663  3659 leader_election.cc:304] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [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: 3a09b4a4d5a2481eab781bf3b028aad2; no voters: 
I20260812 06:20:19.097046  3659 leader_election.cc:290] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.097229  3663 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.097515  3663 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 1 LEADER]: Becoming Leader. State: Replica: 3a09b4a4d5a2481eab781bf3b028aad2, State: Running, Role: LEADER
I20260812 06:20:19.097972  3663 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [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: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER }
I20260812 06:20:19.098167  3659 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.100025  3664 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER } }
I20260812 06:20:19.100010  3667 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3a09b4a4d5a2481eab781bf3b028aad2. Latest consensus state: current_term: 1 leader_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a09b4a4d5a2481eab781bf3b028aad2" member_type: VOTER } }
I20260812 06:20:19.100154  3667 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.100154  3664 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.100526  3554 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:19.102715  3686 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:19.102807  3686 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:19.102876  3685 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.103626  3685 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.108482  3685 catalog_manager.cc:1383] Generated new cluster ID: 2c7475e157ce470cb3e9b37236297eee
I20260812 06:20:19.108559  3685 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.119578  3685 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.120498  3685 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.132833  3685 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: Generated new TSK 0
I20260812 06:20:19.133648  3685 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.165688  3554 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.168545  3694 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:20:19.168641  3696 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:20:19.168803  3554 server_base.cc:1061] running on GCE node
W20260812 06:20:19.168582  3693 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:20:19.169098  3554 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.169157  3554 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:20:19.169179  3554 hybrid_clock.cc:648] HybridClock initialized: now 1786515619169179 us; error 0 us; skew 500 ppm
I20260812 06:20:19.170173  3554 webserver.cc:533] Webserver started at http://127.3.120.129:39561/ using document root <none> and password file <none>
I20260812 06:20:19.170349  3554 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.170413  3554 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.170497  3554 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.170964  3554 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/instance:
uuid: "c10608cf385d4bbba0abbccee6e09758"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-gsp7"
I20260812 06:20:19.172853  3554 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.173998  3702 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:20:19.174296  3554 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:20:19.174386  3554 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root
uuid: "c10608cf385d4bbba0abbccee6e09758"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-gsp7"
I20260812 06:20:19.174489  3554 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-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:20:19.186875  3554 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.187390  3554 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.187961  3554 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.188848  3554 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.188925  3554 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.189026  3554 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.189075  3554 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.196090  3554 rpc_server.cc:307] RPC server started. Bound to: 127.3.120.129:35233
I20260812 06:20:19.196116  3795 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.120.129:35233 every 8 connection(s)
I20260812 06:20:19.206936  3796 heartbeater.cc:344] Connected to a master server at 127.3.120.190:35761
I20260812 06:20:19.207224  3796 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.207692  3796 heartbeater.cc:507] Master 127.3.120.190:35761 requested a full tablet report, sending...
I20260812 06:20:19.209299  3604 ts_manager.cc:194] Registered new tserver with Master: c10608cf385d4bbba0abbccee6e09758 (127.3.120.129:35233)
I20260812 06:20:19.209399  3554 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012606971s
I20260812 06:20:19.210853  3604 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59086
I20260812 06:20:19.220664  3604 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59094:
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:20:19.235376  3744 tablet_service.cc:1511] Processing CreateTablet for tablet ba3c1e261d674adfb4e032defa6766a0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=63f51da7e618499bab90b06082de37b6]), partition=
I20260812 06:20:19.235940  3744 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ba3c1e261d674adfb4e032defa6766a0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.238787  3813 tablet_bootstrap.cc:492] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Bootstrap starting.
I20260812 06:20:19.239993  3813 tablet_bootstrap.cc:654] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.241392  3813 tablet_bootstrap.cc:492] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: No bootstrap required, opened a new log
I20260812 06:20:19.241557  3813 ts_tablet_manager.cc:1403] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.242018  3813 raft_consensus.cc:359] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10608cf385d4bbba0abbccee6e09758" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 35233 } }
I20260812 06:20:19.242148  3813 raft_consensus.cc:385] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.242218  3813 raft_consensus.cc:740] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c10608cf385d4bbba0abbccee6e09758, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.242403  3813 consensus_queue.cc:260] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [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: "c10608cf385d4bbba0abbccee6e09758" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 35233 } }
I20260812 06:20:19.242522  3813 raft_consensus.cc:399] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.242580  3813 raft_consensus.cc:493] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.242642  3813 raft_consensus.cc:3060] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.243573  3813 raft_consensus.cc:515] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10608cf385d4bbba0abbccee6e09758" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 35233 } }
I20260812 06:20:19.243732  3813 leader_election.cc:304] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [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: c10608cf385d4bbba0abbccee6e09758; no voters: 
I20260812 06:20:19.243991  3813 leader_election.cc:290] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.244100  3816 raft_consensus.cc:2804] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.244360  3816 raft_consensus.cc:697] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 1 LEADER]: Becoming Leader. State: Replica: c10608cf385d4bbba0abbccee6e09758, State: Running, Role: LEADER
I20260812 06:20:19.244400  3813 ts_tablet_manager.cc:1434] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.244582  3796 heartbeater.cc:499] Master 127.3.120.190:35761 was elected leader, sending a full tablet report...
I20260812 06:20:19.244565  3816 consensus_queue.cc:237] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [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: "c10608cf385d4bbba0abbccee6e09758" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 35233 } }
I20260812 06:20:19.248077  3604 catalog_manager.cc:5719] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 reported cstate change: term changed from 0 to 1, leader changed from <none> to c10608cf385d4bbba0abbccee6e09758 (127.3.120.129). New cstate: current_term: 1 leader_uuid: "c10608cf385d4bbba0abbccee6e09758" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c10608cf385d4bbba0abbccee6e09758" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 35233 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.318899  3554 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.023s	sys 0.008s
I20260812 06:20:19.447279  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0): perf score=15.086190
I20260812 06:20:19.613600  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.166s	user 0.119s	sys 0.044s Metrics: {"bytes_written":12922857,"cfile_init":1,"compiler_manager_pool.queue_time_us":201,"delete_count":0,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":772,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40985,"lbm_writes_lt_1ms":682,"mutex_wait_us":175,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":132864,"thread_start_us":123,"threads_started":1,"update_count":1575}
I20260812 06:20:19.614897  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling LogGCOp(ba3c1e261d674adfb4e032defa6766a0): free 20743880 bytes of WAL
I20260812 06:20:19.615202  3711 log_reader.cc:385] T ba3c1e261d674adfb4e032defa6766a0: removed 2 log segments from log reader
I20260812 06:20:19.615279  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000001 (ops 1-6)
I20260812 06:20:19.615348  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000002 (ops 7-11)
I20260812 06:20:19.620718  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: LogGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:19.621126  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:19.640316  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3487284,"delete_count":0,"lbm_write_time_us":5253,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:19.640914  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:19.657848  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.658327  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:19.801396  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.143s	user 0.116s	sys 0.024s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364546,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":786,"lbm_read_time_us":8651,"lbm_reads_lt_1ms":555,"lbm_write_time_us":25610,"lbm_writes_lt_1ms":533,"mutex_wait_us":111,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":355,"threads_started":5,"update_count":2450}
I20260812 06:20:19.802001  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0): 12719218 bytes on disk
I20260812 06:20:19.802632  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.803064  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:19.850399  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.047s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16821,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.850862  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:19.861773  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.862541  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:19.990365  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.128s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1308,"lbm_read_time_us":8816,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25158,"lbm_writes_lt_1ms":443,"mutex_wait_us":367,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38656,"update_count":2000}
I20260812 06:20:19.991042  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:20.038127  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.047s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.038648  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:20.049290  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.050058  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:20.170563  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.120s	user 0.095s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":9044,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22961,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:20:20.171207  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:20.224799  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.053s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14366,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.225423  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:20.242906  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.243497  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:20.389827  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.146s	user 0.097s	sys 0.048s 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":1353,"lbm_read_time_us":10754,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22993,"lbm_writes_lt_1ms":443,"mutex_wait_us":408,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:20.390348  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:20.432838  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.042s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17328,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.433346  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:20.446349  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.446820  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:20.575567  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.129s	user 0.097s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":9648,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25621,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":2000}
I20260812 06:20:20.576149  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:20.618052  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.042s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.618572  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:20.629920  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.630470  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:20.756965  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.126s	user 0.082s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":753,"lbm_read_time_us":8938,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24368,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:20:20.758246  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:20.794836  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.036s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15788,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.795481  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:20.808619  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.809203  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:20.845468  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.036s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":313,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1621,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:20.846969  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling LogGCOp(ba3c1e261d674adfb4e032defa6766a0): free 112692374 bytes of WAL
I20260812 06:20:20.847288  3711 log_reader.cc:385] T ba3c1e261d674adfb4e032defa6766a0: removed 11 log segments from log reader
I20260812 06:20:20.847357  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000003 (ops 12-16)
I20260812 06:20:20.847412  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000004 (ops 17-21)
I20260812 06:20:20.847448  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000005 (ops 22-26)
I20260812 06:20:20.847492  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000006 (ops 27-31)
I20260812 06:20:20.847538  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000007 (ops 32-36)
I20260812 06:20:20.847581  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000008 (ops 37-41)
I20260812 06:20:20.847627  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000009 (ops 42-46)
I20260812 06:20:20.847673  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000010 (ops 47-51)
I20260812 06:20:20.847721  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000011 (ops 52-56)
I20260812 06:20:20.847769  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000012 (ops 57-61)
I20260812 06:20:20.847815  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000013 (ops 62-66)
I20260812 06:20:20.872687  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: LogGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:20.873059  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=6.157687
I20260812 06:20:20.893910  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8500,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:20.894443  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling LogGCOp(ba3c1e261d674adfb4e032defa6766a0): free 11564875 bytes of WAL
I20260812 06:20:20.894767  3711 log_reader.cc:385] T ba3c1e261d674adfb4e032defa6766a0: removed 1 log segments from log reader
I20260812 06:20:20.894851  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000014 (ops 67-70)
I20260812 06:20:20.897872  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: LogGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:20.898538  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0): 462 bytes on disk
I20260812 06:20:20.898947  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.899513  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:21.065392  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.166s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2685,"lbm_read_time_us":12356,"lbm_reads_lt_1ms":665,"lbm_write_time_us":33492,"lbm_writes_lt_1ms":643,"mutex_wait_us":1819,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:20:21.066147  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:21.113905  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.048s	user 0.042s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.114449  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:21.126739  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4124,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.127383  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:21.280092  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.152s	user 0.124s	sys 0.028s 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":224,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29470,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:20:21.281267  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=12.110812
I20260812 06:20:21.317639  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.036s	user 0.024s	sys 0.012s Metrics: {"bytes_written":13620265,"delete_count":0,"lbm_write_time_us":15592,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:20:21.322566  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:21.344058  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.021s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:20:21.344522  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:21.354050  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.354496  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:21.532891  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.178s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":11960,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29827,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:21.533614  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:21.585717  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.052s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21042,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.586177  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:21.597142  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.597890  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:21.777652  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.180s	user 0.119s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1935,"lbm_read_time_us":11786,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31906,"lbm_writes_lt_1ms":543,"mutex_wait_us":1276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:20:21.778246  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:21.837704  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.059s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.838255  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:21.849133  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.849673  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.030608  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.181s	user 0.115s	sys 0.060s 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":610,"lbm_read_time_us":13180,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28648,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:20:22.031216  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=11.118625
I20260812 06:20:22.066859  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.035s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15473,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.067476  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:22.087392  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4966,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.088007  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.235140  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.147s	user 0.106s	sys 0.036s 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":1053,"lbm_read_time_us":10379,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22474,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:20:22.235886  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=11.118625
I20260812 06:20:22.277266  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19966,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.277818  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:22.288929  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.289389  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:22.298877  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.009s	user 0.002s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3453,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.299345  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.336510  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1244,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1574,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:22.337286  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling LogGCOp(ba3c1e261d674adfb4e032defa6766a0): free 117302580 bytes of WAL
I20260812 06:20:22.337555  3711 log_reader.cc:385] T ba3c1e261d674adfb4e032defa6766a0: removed 12 log segments from log reader
I20260812 06:20:22.337620  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000015 (ops 71-75)
I20260812 06:20:22.337673  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000016 (ops 76-80)
I20260812 06:20:22.337731  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000017 (ops 81-85)
I20260812 06:20:22.337774  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000018 (ops 86-90)
I20260812 06:20:22.337811  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000019 (ops 91-94)
I20260812 06:20:22.337852  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000020 (ops 95-99)
I20260812 06:20:22.337891  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000021 (ops 100-104)
I20260812 06:20:22.337931  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000022 (ops 105-108)
I20260812 06:20:22.337980  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000023 (ops 109-113)
I20260812 06:20:22.338020  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000024 (ops 114-118)
I20260812 06:20:22.338059  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000025 (ops 119-123)
I20260812 06:20:22.338099  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000026 (ops 124-128)
I20260812 06:20:22.363907  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: LogGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.026s	user 0.005s	sys 0.019s Metrics: {}
I20260812 06:20:22.364324  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0): 472 bytes on disk
I20260812 06:20:22.364902  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0) 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:20:22.365576  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=5.165500
I20260812 06:20:22.388306  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.023s	user 0.009s	sys 0.011s Metrics: {"bytes_written":6358991,"delete_count":0,"lbm_write_time_us":6435,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:20:22.388890  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.394976  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1846277,"delete_count":0,"lbm_write_time_us":1790,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:20:22.395427  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.612179  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.217s	user 0.136s	sys 0.080s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979806,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":277,"lbm_read_time_us":16055,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40376,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":42624,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:22.612682  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:22.672439  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.060s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24816,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.672960  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:22.683939  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.684396  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:22.863432  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.179s	user 0.128s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":13684,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29907,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:20:22.863924  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:22.928592  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.064s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28984,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.929215  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:22.940142  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.940616  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:23.140069  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.199s	user 0.123s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":15946,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30985,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2500}
I20260812 06:20:23.140708  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:23.190975  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.050s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21707,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.191453  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:23.210289  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.210846  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:23.398347  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.187s	user 0.115s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":15943,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29136,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:23.399109  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:23.460976  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.062s	user 0.016s	sys 0.035s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.461623  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:23.472185  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.472855  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:23.658293  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.185s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":11857,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30239,"lbm_writes_lt_1ms":543,"mutex_wait_us":407,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:23.658891  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=14.095187
I20260812 06:20:23.711694  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.053s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21708,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.712244  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:23.728628  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.729353  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:23.890749  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.160s	user 0.111s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":12703,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33342,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:20:23.891415  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=11.118625
I20260812 06:20:23.928575  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16223,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.929201  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:23.949314  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.020s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5637,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.949862  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:24.000777  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushMRSOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.051s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2467,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:24.001566  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling LogGCOp(ba3c1e261d674adfb4e032defa6766a0): free 132571591 bytes of WAL
I20260812 06:20:24.001830  3711 log_reader.cc:385] T ba3c1e261d674adfb4e032defa6766a0: removed 13 log segments from log reader
I20260812 06:20:24.001904  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000027 (ops 129-132)
I20260812 06:20:24.001943  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000028 (ops 133-137)
I20260812 06:20:24.001974  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000029 (ops 138-142)
I20260812 06:20:24.001997  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000030 (ops 143-147)
I20260812 06:20:24.002018  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000031 (ops 148-152)
I20260812 06:20:24.002051  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000032 (ops 153-156)
I20260812 06:20:24.002086  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000033 (ops 157-161)
I20260812 06:20:24.002110  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000034 (ops 162-166)
I20260812 06:20:24.002137  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000035 (ops 167-171)
I20260812 06:20:24.002168  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000036 (ops 172-176)
I20260812 06:20:24.002197  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000037 (ops 177-181)
I20260812 06:20:24.002231  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000038 (ops 182-186)
I20260812 06:20:24.002264  3711 log.cc:1079] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/ba3c1e261d674adfb4e032defa6766a0/wal-000000039 (ops 187-191)
I20260812 06:20:24.036880  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: LogGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.035s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:24.037405  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=6.157687
I20260812 06:20:24.061168  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.023s	user 0.005s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8911,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:24.061771  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=2.188937
I20260812 06:20:24.088624  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.027s	user 0.004s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.089217  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0): 493 bytes on disk
I20260812 06:20:24.089818  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: UndoDeltaBlockGCOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.090400  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0): perf score=1.000000
I20260812 06:20:24.235966  3554 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.917s	user 1.802s	sys 0.162s
I20260812 06:20:24.300005  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: MajorDeltaCompactionOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.209s	user 0.125s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15262,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37272,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:20:24.300578  3797 maintenance_manager.cc:419] P c10608cf385d4bbba0abbccee6e09758: Scheduling FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0): perf score=10.126437
I20260812 06:20:24.325295  3554 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.001s	sys 0.000s
I20260812 06:20:24.326006  3554 tablet_server.cc:179] TabletServer@127.3.120.129:0 shutting down...
I20260812 06:20:24.339550  3711 maintenance_manager.cc:643] P c10608cf385d4bbba0abbccee6e09758: FlushDeltaMemStoresOp(ba3c1e261d674adfb4e032defa6766a0) complete. Timing: real 0.038s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.340165  3554 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.340590  3554 tablet_replica.cc:333] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758: stopping tablet replica
I20260812 06:20:24.340830  3554 raft_consensus.cc:2243] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.341069  3554 raft_consensus.cc:2272] T ba3c1e261d674adfb4e032defa6766a0 P c10608cf385d4bbba0abbccee6e09758 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.345896  3554 tablet_server.cc:196] TabletServer@127.3.120.129:0 shutdown complete.
I20260812 06:20:24.368974  3554 master.cc:562] Master@127.3.120.190:35761 shutting down...
I20260812 06:20:24.373371  3554 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.373615  3554 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.373679  3554 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3a09b4a4d5a2481eab781bf3b028aad2: stopping tablet replica
I20260812 06:20:24.386222  3554 master.cc:584] Master@127.3.120.190:35761 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5467 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:24.485702  3554 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.120.190:41711
I20260812 06:20:24.486083  3554 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.488237  3837 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:20:24.488273  3839 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:20:24.488297  3842 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:20:24.488276  3554 server_base.cc:1061] running on GCE node
I20260812 06:20:24.488600  3554 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.488634  3554 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:20:24.488685  3554 hybrid_clock.cc:648] HybridClock initialized: now 1786515624488684 us; error 0 us; skew 500 ppm
I20260812 06:20:24.489607  3554 webserver.cc:533] Webserver started at http://127.3.120.190:38623/ using document root <none> and password file <none>
I20260812 06:20:24.489789  3554 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.489869  3554 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.489962  3554 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.490402  3554 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/master-0-root/instance:
uuid: "2bae9bdee0c9413dbd3b5e9bd918115a"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-gsp7"
I20260812 06:20:24.492023  3554 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:24.492926  3849 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:20:24.493175  3554 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:24.493251  3554 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/master-0-root
uuid: "2bae9bdee0c9413dbd3b5e9bd918115a"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-gsp7"
I20260812 06:20:24.493310  3554 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-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:20:24.514389  3554 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.514791  3554 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.518929  3554 rpc_server.cc:307] RPC server started. Bound to: 127.3.120.190:41711
I20260812 06:20:24.523921  3934 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.120.190:41711 every 8 connection(s)
I20260812 06:20:24.524307  3935 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:20:24.526597  3935 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a: Bootstrap starting.
I20260812 06:20:24.527395  3935 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.528436  3935 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a: No bootstrap required, opened a new log
I20260812 06:20:24.528856  3935 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER }
I20260812 06:20:24.528973  3935 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.529034  3935 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2bae9bdee0c9413dbd3b5e9bd918115a, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.529212  3935 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [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: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER }
I20260812 06:20:24.529309  3935 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.529352  3935 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.529407  3935 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.530169  3935 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER }
I20260812 06:20:24.530328  3935 leader_election.cc:304] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [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: 2bae9bdee0c9413dbd3b5e9bd918115a; no voters: 
I20260812 06:20:24.530560  3935 leader_election.cc:290] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.530699  3939 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.530894  3939 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 1 LEADER]: Becoming Leader. State: Replica: 2bae9bdee0c9413dbd3b5e9bd918115a, State: Running, Role: LEADER
I20260812 06:20:24.531049  3939 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [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: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER }
I20260812 06:20:24.531071  3935 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:24.531527  3941 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER } }
I20260812 06:20:24.531592  3943 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2bae9bdee0c9413dbd3b5e9bd918115a. Latest consensus state: current_term: 1 leader_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bae9bdee0c9413dbd3b5e9bd918115a" member_type: VOTER } }
I20260812 06:20:24.531638  3941 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.531740  3943 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.532065  3947 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:24.533073  3947 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:24.533316  3554 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:24.534965  3947 catalog_manager.cc:1383] Generated new cluster ID: 7dcac6d5015e4597889ed2b2b99c9102
I20260812 06:20:24.535022  3947 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:24.540176  3947 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:24.540752  3947 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:24.549976  3947 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a: Generated new TSK 0
I20260812 06:20:24.550232  3947 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:24.566175  3554 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.568382  3964 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:20:24.568470  3554 server_base.cc:1061] running on GCE node
W20260812 06:20:24.568493  3966 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:20:24.568590  3968 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:20:24.568889  3554 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.568933  3554 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:20:24.568979  3554 hybrid_clock.cc:648] HybridClock initialized: now 1786515624568978 us; error 0 us; skew 500 ppm
I20260812 06:20:24.569934  3554 webserver.cc:533] Webserver started at http://127.3.120.129:41185/ using document root <none> and password file <none>
I20260812 06:20:24.570111  3554 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.570158  3554 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.570211  3554 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.570576  3554 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/instance:
uuid: "c67732f2c4c44192ae1ef6ead481ea7a"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-gsp7"
I20260812 06:20:24.572088  3554 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:24.573110  3973 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:20:24.573352  3554 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:24.573416  3554 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root
uuid: "c67732f2c4c44192ae1ef6ead481ea7a"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-gsp7"
I20260812 06:20:24.573552  3554 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-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:20:24.597865  3554 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.598341  3554 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.598680  3554 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.599195  3554 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.599234  3554 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.599298  3554 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.599340  3554 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.603989  3554 rpc_server.cc:307] RPC server started. Bound to: 127.3.120.129:42763
I20260812 06:20:24.605036  4063 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.120.129:42763 every 8 connection(s)
I20260812 06:20:24.612944  4067 heartbeater.cc:344] Connected to a master server at 127.3.120.190:41711
I20260812 06:20:24.613094  4067 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.613355  4067 heartbeater.cc:507] Master 127.3.120.190:41711 requested a full tablet report, sending...
I20260812 06:20:24.614113  3873 ts_manager.cc:194] Registered new tserver with Master: c67732f2c4c44192ae1ef6ead481ea7a (127.3.120.129:42763)
I20260812 06:20:24.614813  3873 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45396
I20260812 06:20:24.615082  3554 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010146138s
I20260812 06:20:24.622433  3873 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45404:
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:20:24.631639  4014 tablet_service.cc:1511] Processing CreateTablet for tablet 1bc30737e8ed41e3b6be3f428ed67fe4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c271cfcbd08e4baeb8a8d82ff35a20d2]), partition=
I20260812 06:20:24.631960  4014 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1bc30737e8ed41e3b6be3f428ed67fe4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.634459  4089 tablet_bootstrap.cc:492] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Bootstrap starting.
I20260812 06:20:24.635373  4089 tablet_bootstrap.cc:654] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.636541  4089 tablet_bootstrap.cc:492] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: No bootstrap required, opened a new log
I20260812 06:20:24.636641  4089 ts_tablet_manager.cc:1403] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:24.637226  4089 raft_consensus.cc:359] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c67732f2c4c44192ae1ef6ead481ea7a" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 42763 } }
I20260812 06:20:24.637354  4089 raft_consensus.cc:385] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.637418  4089 raft_consensus.cc:740] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c67732f2c4c44192ae1ef6ead481ea7a, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.637596  4089 consensus_queue.cc:260] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [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: "c67732f2c4c44192ae1ef6ead481ea7a" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 42763 } }
I20260812 06:20:24.637670  4089 raft_consensus.cc:399] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.637728  4089 raft_consensus.cc:493] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.637784  4089 raft_consensus.cc:3060] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.638543  4089 raft_consensus.cc:515] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c67732f2c4c44192ae1ef6ead481ea7a" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 42763 } }
I20260812 06:20:24.638700  4089 leader_election.cc:304] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [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: c67732f2c4c44192ae1ef6ead481ea7a; no voters: 
I20260812 06:20:24.638923  4089 leader_election.cc:290] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.639061  4092 raft_consensus.cc:2804] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.639281  4089 ts_tablet_manager.cc:1434] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:24.639328  4092 raft_consensus.cc:697] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 1 LEADER]: Becoming Leader. State: Replica: c67732f2c4c44192ae1ef6ead481ea7a, State: Running, Role: LEADER
I20260812 06:20:24.639310  4067 heartbeater.cc:499] Master 127.3.120.190:41711 was elected leader, sending a full tablet report...
I20260812 06:20:24.639523  4092 consensus_queue.cc:237] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [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: "c67732f2c4c44192ae1ef6ead481ea7a" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 42763 } }
I20260812 06:20:24.640869  3873 catalog_manager.cc:5719] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a reported cstate change: term changed from 0 to 1, leader changed from <none> to c67732f2c4c44192ae1ef6ead481ea7a (127.3.120.129). New cstate: current_term: 1 leader_uuid: "c67732f2c4c44192ae1ef6ead481ea7a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c67732f2c4c44192ae1ef6ead481ea7a" member_type: VOTER last_known_addr { host: "127.3.120.129" port: 42763 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:24.699636  3554 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.011s	sys 0.012s
I20260812 06:20:24.855669  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=19.054940
I20260812 06:20:25.008983  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.153s	user 0.114s	sys 0.036s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1351,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37104,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:25.009856  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): free 20290830 bytes of WAL
I20260812 06:20:25.010115  3981 log_reader.cc:385] T 1bc30737e8ed41e3b6be3f428ed67fe4: removed 2 log segments from log reader
I20260812 06:20:25.010188  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000001 (ops 1-6)
I20260812 06:20:25.010246  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000002 (ops 7-10)
I20260812 06:20:25.015314  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:25.015749  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): 16411393 bytes on disk
I20260812 06:20:25.016290  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.016754  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:25.036286  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.019s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.036854  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:25.200960  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.164s	user 0.105s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":658,"lbm_read_time_us":10559,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24425,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":354,"threads_started":5,"update_count":2000}
I20260812 06:20:25.201766  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:25.247723  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.046s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":19995,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.248265  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:25.400784  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.152s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672162,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":361,"lbm_read_time_us":11589,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23145,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:20:25.401662  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=11.118625
I20260812 06:20:25.437129  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.035s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15417,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.437772  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:25.461222  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5615,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.461753  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:25.474973  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.475600  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:25.652005  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.176s	user 0.115s	sys 0.057s 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":195,"lbm_read_time_us":11760,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29324,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:25.652685  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:25.702800  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.703358  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:25.715909  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.716563  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:25.867681  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.151s	user 0.110s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":10378,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28141,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:25.868276  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=11.118625
I20260812 06:20:25.897236  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.029s	user 0.019s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12507,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.898089  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:25.914237  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.914776  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:26.039153  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.124s	user 0.103s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":8255,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22499,"lbm_writes_lt_1ms":443,"mutex_wait_us":99,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:20:26.039909  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=10.126437
I20260812 06:20:26.081975  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.042s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15908,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.082612  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.098750  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.099316  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:26.233842  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.134s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":12223,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23919,"lbm_writes_lt_1ms":443,"mutex_wait_us":172,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:20:26.234761  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=10.126437
I20260812 06:20:26.279105  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14731,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.279706  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.290609  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.291131  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:26.334334  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.043s	user 0.036s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":178,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1305,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2017,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:26.335014  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): free 121459483 bytes of WAL
I20260812 06:20:26.335311  3981 log_reader.cc:385] T 1bc30737e8ed41e3b6be3f428ed67fe4: removed 12 log segments from log reader
I20260812 06:20:26.335376  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000003 (ops 11-15)
I20260812 06:20:26.335414  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000004 (ops 16-20)
I20260812 06:20:26.335446  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000005 (ops 21-25)
I20260812 06:20:26.335481  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000006 (ops 26-30)
I20260812 06:20:26.335510  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000007 (ops 31-35)
I20260812 06:20:26.335533  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000008 (ops 36-40)
I20260812 06:20:26.335556  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000009 (ops 41-45)
I20260812 06:20:26.335585  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000010 (ops 46-50)
I20260812 06:20:26.335616  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000011 (ops 51-55)
I20260812 06:20:26.335649  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000012 (ops 56-60)
I20260812 06:20:26.335675  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000013 (ops 61-65)
I20260812 06:20:26.335703  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000014 (ops 66-70)
I20260812 06:20:26.364038  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:26.364612  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.392443  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.028s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.392964  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.408056  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.408658  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): 471 bytes on disk
I20260812 06:20:26.409335  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.409897  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:26.613713  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.204s	user 0.136s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1228,"lbm_read_time_us":13082,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32777,"lbm_writes_lt_1ms":643,"mutex_wait_us":1098,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:20:26.614508  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=15.087375
I20260812 06:20:26.668782  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.054s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24630,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:26.669342  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.681735  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.682324  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:26.864351  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.182s	user 0.114s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":13396,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30219,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:20:26.865011  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:26.919543  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.054s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20974,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.920111  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:26.931767  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.932247  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:27.114043  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.182s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":12831,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29983,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:20:27.114641  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:27.182385  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.068s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22812,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.182943  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:27.193879  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.194465  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:27.382340  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.188s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":12775,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29814,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56832,"update_count":2500}
I20260812 06:20:27.383057  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:27.432126  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.049s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.432781  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:27.454638  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.455212  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:27.635689  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.180s	user 0.118s	sys 0.060s 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":175,"lbm_read_time_us":12835,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27632,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:20:27.636266  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:27.687346  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.051s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25166,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.687836  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:27.700398  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.700872  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:27.887183  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.186s	user 0.130s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":11920,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28854,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:20:27.887976  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:27.943856  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.056s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27796,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.944495  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:27.974920  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.030s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.975441  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:27.987504  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.988306  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:28.031041  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.043s	user 0.032s	sys 0.009s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2280,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:28.031733  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): free 140885361 bytes of WAL
I20260812 06:20:28.032035  3981 log_reader.cc:385] T 1bc30737e8ed41e3b6be3f428ed67fe4: removed 14 log segments from log reader
I20260812 06:20:28.032121  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000015 (ops 71-74)
I20260812 06:20:28.032189  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000016 (ops 75-79)
I20260812 06:20:28.032284  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000017 (ops 80-84)
I20260812 06:20:28.032332  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000018 (ops 85-88)
I20260812 06:20:28.032377  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000019 (ops 89-93)
I20260812 06:20:28.032419  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000020 (ops 94-98)
I20260812 06:20:28.032462  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000021 (ops 99-103)
I20260812 06:20:28.032519  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000022 (ops 104-108)
I20260812 06:20:28.032562  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000023 (ops 109-113)
I20260812 06:20:28.032603  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000024 (ops 114-118)
I20260812 06:20:28.032646  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000025 (ops 119-123)
I20260812 06:20:28.032688  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000026 (ops 124-128)
I20260812 06:20:28.032732  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000027 (ops 129-132)
I20260812 06:20:28.032774  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000028 (ops 133-137)
I20260812 06:20:28.064508  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:28.064986  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): 508 bytes on disk
I20260812 06:20:28.065701  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.066273  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=3.181125
I20260812 06:20:28.080073  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4894,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.080610  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:28.095407  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5443,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.096048  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:28.349370  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.253s	user 0.134s	sys 0.116s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":308,"lbm_read_time_us":17548,"lbm_reads_lt_1ms":875,"lbm_write_time_us":42737,"lbm_writes_lt_1ms":843,"mutex_wait_us":41,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":87,"threads_started":1,"update_count":4000}
I20260812 06:20:28.350180  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=18.063937
I20260812 06:20:28.433894  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.083s	user 0.048s	sys 0.020s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30219,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.434473  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:28.450330  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.450875  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:28.661808  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.211s	user 0.137s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1392,"lbm_read_time_us":13591,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33668,"lbm_writes_lt_1ms":643,"mutex_wait_us":704,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:20:28.662472  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:28.703732  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.041s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:28.704253  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:28.719419  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.720114  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:28.892956  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.173s	user 0.117s	sys 0.056s 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":166,"lbm_read_time_us":13808,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30421,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:28.893693  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:28.955076  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.061s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24069,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.955709  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:28.967289  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.967943  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:29.155437  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.187s	user 0.113s	sys 0.067s 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":1224,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29632,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:20:29.156034  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:29.221426  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.065s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22510,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.222038  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:29.233620  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.234186  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:29.435678  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.201s	user 0.116s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":14773,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32826,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":2500}
I20260812 06:20:29.436452  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=14.095187
I20260812 06:20:29.490314  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.053s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24058,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.490882  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:29.512563  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.021s	user 0.012s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.513432  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:29.560953  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushMRSOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.047s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1291,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:29.562016  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=3.181125
I20260812 06:20:29.576105  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":4485,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:20:29.576704  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): free 112239552 bytes of WAL
I20260812 06:20:29.576962  3981 log_reader.cc:385] T 1bc30737e8ed41e3b6be3f428ed67fe4: removed 11 log segments from log reader
I20260812 06:20:29.577033  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000029 (ops 138-142)
I20260812 06:20:29.577088  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000030 (ops 143-147)
I20260812 06:20:29.577147  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000031 (ops 148-152)
I20260812 06:20:29.577188  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000032 (ops 153-156)
I20260812 06:20:29.577224  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000033 (ops 157-161)
I20260812 06:20:29.577260  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000034 (ops 162-166)
I20260812 06:20:29.577294  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000035 (ops 167-171)
I20260812 06:20:29.577325  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000036 (ops 172-176)
I20260812 06:20:29.577363  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000037 (ops 177-181)
I20260812 06:20:29.577400  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000038 (ops 182-186)
I20260812 06:20:29.577438  3981 log.cc:1079] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: Deleting log segment in path: /tmp/dist-test-taskQcyFuE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618995984-3554-0/minicluster-data/ts-0-root/wals/1bc30737e8ed41e3b6be3f428ed67fe4/wal-000000039 (ops 187-191)
I20260812 06:20:29.602707  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: LogGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:20:29.603202  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4): 446 bytes on disk
I20260812 06:20:29.603839  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: UndoDeltaBlockGCOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.604423  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:29.625378  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.021s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":6721,"lbm_writes_lt_1ms":106,"mutex_wait_us":827,"reinsert_count":0,"update_count":515}
I20260812 06:20:29.625905  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=2.188937
I20260812 06:20:29.636157  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: FlushDeltaMemStoresOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:29.636595  4069 maintenance_manager.cc:419] P c67732f2c4c44192ae1ef6ead481ea7a: Scheduling MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4): perf score=1.000000
I20260812 06:20:29.724182  3554 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.024s	user 1.830s	sys 0.224s
I20260812 06:20:29.840603  3554 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.116s	user 0.001s	sys 0.000s
I20260812 06:20:29.841132  3554 tablet_server.cc:179] TabletServer@127.3.120.129:0 shutting down...
I20260812 06:20:29.889010  3981 maintenance_manager.cc:643] P c67732f2c4c44192ae1ef6ead481ea7a: MajorDeltaCompactionOp(1bc30737e8ed41e3b6be3f428ed67fe4) complete. Timing: real 0.252s	user 0.170s	sys 0.081s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":734,"lbm_read_time_us":19518,"lbm_reads_lt_1ms":871,"lbm_write_time_us":39401,"lbm_writes_lt_1ms":843,"mutex_wait_us":94,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":87,"threads_started":1,"update_count":4000}
I20260812 06:20:29.889621  3554 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:29.889978  3554 tablet_replica.cc:333] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a: stopping tablet replica
I20260812 06:20:29.890158  3554 raft_consensus.cc:2243] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.890347  3554 raft_consensus.cc:2272] T 1bc30737e8ed41e3b6be3f428ed67fe4 P c67732f2c4c44192ae1ef6ead481ea7a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.896422  3554 tablet_server.cc:196] TabletServer@127.3.120.129:0 shutdown complete.
I20260812 06:20:29.960475  3554 master.cc:562] Master@127.3.120.190:41711 shutting down...
I20260812 06:20:29.964316  3554 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.964562  3554 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.964656  3554 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2bae9bdee0c9413dbd3b5e9bd918115a: stopping tablet replica
I20260812 06:20:29.977244  3554 master.cc:584] Master@127.3.120.190:41711 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5590 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11058 ms total)

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