[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:07.514119 20799 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.79.254:36587
I20260812 06:18:07.515221 20799 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:07.515858 20799 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:07.522931 20816 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.523077 20799 server_base.cc:1061] running on GCE node
W20260812 06:18:07.523010 20813 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:07.523186 20810 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.523736 20799 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:07.523851 20799 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:07.523919 20799 hybrid_clock.cc:648] HybridClock initialized: now 1786515487523902 us; error 0 us; skew 500 ppm
I20260812 06:18:07.525796 20799 webserver.cc:533] Webserver started at http://127.20.79.254:36939/ using document root <none> and password file <none>
I20260812 06:18:07.526368 20799 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:07.526430 20799 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:07.526727 20799 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:07.528533 20799 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/master-0-root/instance:
uuid: "39cb4725871b4026b3e9f90df6a9ca8e"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-h6n0"
I20260812 06:18:07.532188 20799 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:18:07.534386 20827 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.535766 20799 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:07.535874 20799 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/master-0-root
uuid: "39cb4725871b4026b3e9f90df6a9ca8e"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-h6n0"
I20260812 06:18:07.536024 20799 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:07.558390 20799 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:07.559144 20799 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:07.559295 20799 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:07.567374 20799 rpc_server.cc:307] RPC server started. Bound to: 127.20.79.254:36587
I20260812 06:18:07.567529 20917 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.79.254:36587 every 8 connection(s)
I20260812 06:18:07.570061 20918 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:07.576236 20918 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: Bootstrap starting.
I20260812 06:18:07.579015 20918 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:07.579993 20918 log.cc:826] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:07.582247 20918 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: No bootstrap required, opened a new log
I20260812 06:18:07.585372 20918 raft_consensus.cc:359] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER }
I20260812 06:18:07.585602 20918 raft_consensus.cc:385] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:07.585717 20918 raft_consensus.cc:740] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 39cb4725871b4026b3e9f90df6a9ca8e, State: Initialized, Role: FOLLOWER
I20260812 06:18:07.586347 20918 consensus_queue.cc:260] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [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: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER }
I20260812 06:18:07.586580 20918 raft_consensus.cc:399] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:07.586683 20918 raft_consensus.cc:493] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:07.586826 20918 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:07.587713 20918 raft_consensus.cc:515] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER }
I20260812 06:18:07.588207 20918 leader_election.cc:304] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [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: 39cb4725871b4026b3e9f90df6a9ca8e; no voters: 
I20260812 06:18:07.588570 20918 leader_election.cc:290] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:07.588780 20921 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:07.589114 20921 raft_consensus.cc:697] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 1 LEADER]: Becoming Leader. State: Replica: 39cb4725871b4026b3e9f90df6a9ca8e, State: Running, Role: LEADER
I20260812 06:18:07.589540 20921 consensus_queue.cc:237] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [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: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER }
I20260812 06:18:07.589680 20918 sys_catalog.cc:565] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:07.591904 20925 sys_catalog.cc:455] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 39cb4725871b4026b3e9f90df6a9ca8e. Latest consensus state: current_term: 1 leader_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER } }
I20260812 06:18:07.591984 20924 sys_catalog.cc:455] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39cb4725871b4026b3e9f90df6a9ca8e" member_type: VOTER } }
I20260812 06:18:07.592056 20925 sys_catalog.cc:458] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:07.592093 20924 sys_catalog.cc:458] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:07.592343 20799 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:07.592423 20940 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:07.595924 20940 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:07.602169 20940 catalog_manager.cc:1383] Generated new cluster ID: f160b9f6562c426c9d28abbc1ca79da8
I20260812 06:18:07.602294 20940 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:07.636883 20940 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:07.637856 20940 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:07.643365 20940 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: Generated new TSK 0
I20260812 06:18:07.644410 20940 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:07.657692 20799 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:07.661489 20948 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:07.661490 20949 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:07.661736 20951 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.662168 20799 server_base.cc:1061] running on GCE node
I20260812 06:18:07.662503 20799 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:07.662635 20799 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:07.662655 20799 hybrid_clock.cc:648] HybridClock initialized: now 1786515487662656 us; error 0 us; skew 500 ppm
I20260812 06:18:07.663745 20799 webserver.cc:533] Webserver started at http://127.20.79.193:40409/ using document root <none> and password file <none>
I20260812 06:18:07.663964 20799 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:07.664012 20799 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:07.664116 20799 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:07.664549 20799 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/instance:
uuid: "bcd659a946ff473d89518eb5b5d9c839"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-h6n0"
I20260812 06:18:07.666783 20799 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:07.668210 20959 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.668551 20799 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:07.668671 20799 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root
uuid: "bcd659a946ff473d89518eb5b5d9c839"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-h6n0"
I20260812 06:18:07.668785 20799 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:07.690255 20799 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:07.690886 20799 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:07.691565 20799 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:07.692474 20799 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:07.692528 20799 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.692615 20799 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:07.692651 20799 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.700675 20799 rpc_server.cc:307] RPC server started. Bound to: 127.20.79.193:34887
I20260812 06:18:07.700714 21063 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.79.193:34887 every 8 connection(s)
I20260812 06:18:07.713078 21064 heartbeater.cc:344] Connected to a master server at 127.20.79.254:36587
I20260812 06:18:07.713565 21064 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:07.714367 21064 heartbeater.cc:507] Master 127.20.79.254:36587 requested a full tablet report, sending...
I20260812 06:18:07.716212 20855 ts_manager.cc:194] Registered new tserver with Master: bcd659a946ff473d89518eb5b5d9c839 (127.20.79.193:34887)
I20260812 06:18:07.716430 20799 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015050862s
I20260812 06:18:07.717725 20855 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33554
I20260812 06:18:07.727841 20855 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33570:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:07.743721 21006 tablet_service.cc:1511] Processing CreateTablet for tablet 2a24d45361dd4a08afb28679952b5b88 (DEFAULT_TABLE table=heavy-update-compaction-test [id=66b97dc880b947b7b1a091316565a28e]), partition=
I20260812 06:18:07.744256 21006 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2a24d45361dd4a08afb28679952b5b88. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:07.747618 21083 tablet_bootstrap.cc:492] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Bootstrap starting.
I20260812 06:18:07.748813 21083 tablet_bootstrap.cc:654] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:07.750507 21083 tablet_bootstrap.cc:492] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: No bootstrap required, opened a new log
I20260812 06:18:07.750777 21083 ts_tablet_manager.cc:1403] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:18:07.751492 21083 raft_consensus.cc:359] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcd659a946ff473d89518eb5b5d9c839" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 34887 } }
I20260812 06:18:07.751660 21083 raft_consensus.cc:385] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:07.751718 21083 raft_consensus.cc:740] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bcd659a946ff473d89518eb5b5d9c839, State: Initialized, Role: FOLLOWER
I20260812 06:18:07.751931 21083 consensus_queue.cc:260] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [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: "bcd659a946ff473d89518eb5b5d9c839" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 34887 } }
I20260812 06:18:07.752060 21083 raft_consensus.cc:399] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:07.752117 21083 raft_consensus.cc:493] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:07.752177 21083 raft_consensus.cc:3060] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:07.753206 21083 raft_consensus.cc:515] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcd659a946ff473d89518eb5b5d9c839" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 34887 } }
I20260812 06:18:07.753407 21083 leader_election.cc:304] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [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: bcd659a946ff473d89518eb5b5d9c839; no voters: 
I20260812 06:18:07.753698 21083 leader_election.cc:290] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:07.753922 21088 raft_consensus.cc:2804] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:07.754206 21088 raft_consensus.cc:697] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 1 LEADER]: Becoming Leader. State: Replica: bcd659a946ff473d89518eb5b5d9c839, State: Running, Role: LEADER
I20260812 06:18:07.754280 21083 ts_tablet_manager.cc:1434] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:07.754765 21088 consensus_queue.cc:237] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [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: "bcd659a946ff473d89518eb5b5d9c839" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 34887 } }
I20260812 06:18:07.754887 21064 heartbeater.cc:499] Master 127.20.79.254:36587 was elected leader, sending a full tablet report...
I20260812 06:18:07.757463 20855 catalog_manager.cc:5719] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 reported cstate change: term changed from 0 to 1, leader changed from <none> to bcd659a946ff473d89518eb5b5d9c839 (127.20.79.193). New cstate: current_term: 1 leader_uuid: "bcd659a946ff473d89518eb5b5d9c839" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcd659a946ff473d89518eb5b5d9c839" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 34887 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:07.831153 20799 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.023s	sys 0.008s
I20260812 06:18:07.952176 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushMRSOp(2a24d45361dd4a08afb28679952b5b88): perf score=15.086190
I20260812 06:18:08.107298 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushMRSOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.155s	user 0.110s	sys 0.044s Metrics: {"bytes_written":8615324,"cfile_init":1,"compiler_manager_pool.queue_time_us":303,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":661,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35165,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":182,"threads_started":1,"update_count":1050}
I20260812 06:18:08.108629 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling LogGCOp(2a24d45361dd4a08afb28679952b5b88): free 11976772 bytes of WAL
I20260812 06:18:08.108937 20967 log_reader.cc:385] T 2a24d45361dd4a08afb28679952b5b88: removed 1 log segments from log reader
I20260812 06:18:08.109033 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000001 (ops 1-6)
I20260812 06:18:08.113096 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: LogGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:08.113569 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88): 12308959 bytes on disk
I20260812 06:18:08.114241 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:08.114725 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:08.132972 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5859,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.133836 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:08.261112 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.127s	user 0.080s	sys 0.039s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528892,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":492,"lbm_read_time_us":5874,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21043,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":338,"threads_started":5,"update_count":1500}
I20260812 06:18:08.261826 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:08.315843 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.054s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18115,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.316499 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:08.331804 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.332660 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:08.469117 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.136s	user 0.101s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":127,"lbm_read_time_us":7833,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28054,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:08.469713 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:08.527539 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.058s	user 0.028s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19386,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.528327 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:08.542357 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.543047 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:08.700291 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.157s	user 0.099s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":734,"lbm_read_time_us":10316,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27073,"lbm_writes_lt_1ms":443,"mutex_wait_us":262,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:18:08.700838 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:08.752158 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.051s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.752658 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:08.764639 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.765264 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:08.900830 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.135s	user 0.110s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1620,"lbm_read_time_us":9127,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26563,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":87424,"update_count":2000}
I20260812 06:18:08.901624 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:08.964641 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.063s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":27135,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.965341 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:08.977844 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.978644 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:09.113881 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.135s	user 0.105s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":773,"lbm_read_time_us":10923,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24754,"lbm_writes_lt_1ms":443,"mutex_wait_us":331,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28032,"update_count":2000}
I20260812 06:18:09.114516 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:09.164518 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.050s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.165320 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:09.184114 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.019s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.184763 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:09.339460 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.154s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":775,"lbm_read_time_us":11042,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25316,"lbm_writes_lt_1ms":443,"mutex_wait_us":361,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":2000}
I20260812 06:18:09.340165 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:09.384315 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.044s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":13768,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.384967 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:09.395777 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.396369 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:09.539681 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.143s	user 0.114s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":794,"lbm_read_time_us":8975,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26970,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":79488,"update_count":2000}
I20260812 06:18:09.540328 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:09.593884 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.053s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17826,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.594659 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:09.612593 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.613149 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushMRSOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:09.650199 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushMRSOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.037s	user 0.028s	sys 0.008s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":283,"dirs.run_wall_time_us":1145,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2263,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:09.651214 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling LogGCOp(2a24d45361dd4a08afb28679952b5b88): free 129320484 bytes of WAL
I20260812 06:18:09.651479 20967 log_reader.cc:385] T 2a24d45361dd4a08afb28679952b5b88: removed 13 log segments from log reader
I20260812 06:18:09.651551 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000002 (ops 7-11)
I20260812 06:18:09.651602 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000003 (ops 12-16)
I20260812 06:18:09.651660 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000004 (ops 17-21)
I20260812 06:18:09.651705 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000005 (ops 22-26)
I20260812 06:18:09.651746 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000006 (ops 27-30)
I20260812 06:18:09.651799 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000007 (ops 31-35)
I20260812 06:18:09.651836 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000008 (ops 36-40)
I20260812 06:18:09.651875 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000009 (ops 41-45)
I20260812 06:18:09.651914 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000010 (ops 46-50)
I20260812 06:18:09.651948 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000011 (ops 51-55)
I20260812 06:18:09.651988 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000012 (ops 56-60)
I20260812 06:18:09.652027 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000013 (ops 61-64)
I20260812 06:18:09.652066 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000014 (ops 65-69)
I20260812 06:18:09.678700 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: LogGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:09.679298 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88): 483 bytes on disk
I20260812 06:18:09.680039 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":174,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.680717 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=3.181125
I20260812 06:18:09.696112 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6174,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:09.696616 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:09.710680 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5422,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.711364 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:09.890058 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.179s	user 0.123s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836365,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":601,"lbm_read_time_us":11229,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35915,"lbm_writes_lt_1ms":643,"mutex_wait_us":305,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:18:09.890739 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:09.941854 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.051s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.942443 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:09.959038 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.959698 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:10.150065 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.190s	user 0.134s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":9400,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38230,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:10.150717 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:10.203301 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.052s	user 0.036s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.203766 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:10.214215 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.214905 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:10.399063 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.184s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":11421,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34590,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:18:10.399740 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:10.462036 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.062s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21467,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.462832 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:10.476095 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.476567 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:10.658409 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.182s	user 0.142s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":12314,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28807,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:18:10.659049 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:10.714761 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.055s	user 0.042s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24661,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.715317 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:10.877848 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.162s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":670,"lbm_read_time_us":11886,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27807,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.878705 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:10.922233 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.043s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19316,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.922979 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:10.943411 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.943961 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:11.076000 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.132s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":7594,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24553,"lbm_writes_lt_1ms":443,"mutex_wait_us":114,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:11.076839 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:11.122272 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.045s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17606,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.123019 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.134966 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.135973 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushMRSOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:11.165735 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushMRSOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.030s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":149,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1187,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:11.166917 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling LogGCOp(2a24d45361dd4a08afb28679952b5b88): free 124257248 bytes of WAL
I20260812 06:18:11.167240 20967 log_reader.cc:385] T 2a24d45361dd4a08afb28679952b5b88: removed 12 log segments from log reader
I20260812 06:18:11.167305 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000015 (ops 70-74)
I20260812 06:18:11.167346 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000016 (ops 75-79)
I20260812 06:18:11.167379 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000017 (ops 80-84)
I20260812 06:18:11.167412 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000018 (ops 85-89)
I20260812 06:18:11.167438 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000019 (ops 90-94)
I20260812 06:18:11.167462 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000020 (ops 95-99)
I20260812 06:18:11.167487 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000021 (ops 100-104)
I20260812 06:18:11.167515 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000022 (ops 105-109)
I20260812 06:18:11.167557 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000023 (ops 110-114)
I20260812 06:18:11.167593 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000024 (ops 115-118)
I20260812 06:18:11.167616 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000025 (ops 119-123)
I20260812 06:18:11.167639 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000026 (ops 124-128)
I20260812 06:18:11.200273 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: LogGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:11.200748 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.226136 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.025s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.226706 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88): 462 bytes on disk
I20260812 06:18:11.227128 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.227620 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.238758 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.239230 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:11.426517 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.187s	user 0.128s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836372,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":468,"lbm_read_time_us":13403,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36373,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21248,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:18:11.427922 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:11.487517 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.059s	user 0.045s	sys 0.007s Metrics: {"bytes_written":16409947,"delete_count":0,"lbm_write_time_us":24169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.488139 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.500754 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.501252 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:11.653285 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.152s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":10521,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33093,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.653949 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=11.118625
I20260812 06:18:11.687513 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.033s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14014,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.687983 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.715196 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.027s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.715777 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.727490 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.728155 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:11.887208 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.159s	user 0.109s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733832,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":299,"lbm_read_time_us":12587,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32373,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:11.887864 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=11.118625
I20260812 06:18:11.919349 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.031s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13664,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.919862 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:11.936201 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6515,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.936781 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.065315 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.128s	user 0.092s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":7410,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29226,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:18:12.066002 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:12.112088 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.046s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.112684 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:12.123118 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.123703 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.282140 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.158s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":482,"lbm_read_time_us":10814,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28656,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:12.282918 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:12.330566 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.047s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.331097 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:12.347235 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.347916 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.491917 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.144s	user 0.120s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":9478,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30926,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.492556 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=10.126437
I20260812 06:18:12.542754 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.050s	user 0.039s	sys 0.001s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17909,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.543285 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:12.558460 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.558967 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushMRSOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.587805 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushMRSOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1190,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1863,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:12.588507 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling LogGCOp(2a24d45361dd4a08afb28679952b5b88): free 112239552 bytes of WAL
I20260812 06:18:12.588719 20967 log_reader.cc:385] T 2a24d45361dd4a08afb28679952b5b88: removed 11 log segments from log reader
I20260812 06:18:12.588761 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000027 (ops 129-133)
I20260812 06:18:12.588788 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000028 (ops 134-138)
I20260812 06:18:12.588850 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000029 (ops 139-142)
I20260812 06:18:12.588891 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000030 (ops 143-147)
I20260812 06:18:12.588936 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000031 (ops 148-152)
I20260812 06:18:12.588997 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000032 (ops 153-157)
I20260812 06:18:12.589041 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000033 (ops 158-162)
I20260812 06:18:12.589082 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000034 (ops 163-167)
I20260812 06:18:12.589121 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000035 (ops 168-172)
I20260812 06:18:12.589159 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000036 (ops 173-177)
I20260812 06:18:12.589197 20967 log.cc:1079] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/2a24d45361dd4a08afb28679952b5b88/wal-000000037 (ops 178-182)
I20260812 06:18:12.613400 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: LogGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:12.613938 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=3.181125
I20260812 06:18:12.627817 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5120,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:12.628314 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:12.642447 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5708,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.643064 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.824344 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.181s	user 0.150s	sys 0.026s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836366,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":685,"lbm_read_time_us":12110,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36712,"lbm_writes_lt_1ms":643,"mutex_wait_us":343,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:18:12.825028 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88): 448 bytes on disk
I20260812 06:18:12.825510 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: UndoDeltaBlockGCOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.826073 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=14.095187
I20260812 06:18:12.873538 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.047s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409885,"delete_count":0,"lbm_write_time_us":21696,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.874121 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88): perf score=2.188937
I20260812 06:18:12.887679 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: FlushDeltaMemStoresOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.888335 21065 maintenance_manager.cc:419] P bcd659a946ff473d89518eb5b5d9c839: Scheduling MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88): perf score=1.000000
I20260812 06:18:12.965190 20799 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.134s	user 1.986s	sys 0.095s
I20260812 06:18:13.033547 20799 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.001s	sys 0.000s
I20260812 06:18:13.034142 20799 tablet_server.cc:179] TabletServer@127.20.79.193:0 shutting down...
I20260812 06:18:13.045361 20967 maintenance_manager.cc:643] P bcd659a946ff473d89518eb5b5d9c839: MajorDeltaCompactionOp(2a24d45361dd4a08afb28679952b5b88) complete. Timing: real 0.157s	user 0.111s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733707,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1623,"lbm_read_time_us":11240,"lbm_reads_lt_1ms":560,"lbm_write_time_us":34762,"lbm_writes_lt_1ms":543,"mutex_wait_us":404,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:13.045898 20799 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:13.046283 20799 tablet_replica.cc:333] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839: stopping tablet replica
I20260812 06:18:13.046563 20799 raft_consensus.cc:2243] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:13.046802 20799 raft_consensus.cc:2272] T 2a24d45361dd4a08afb28679952b5b88 P bcd659a946ff473d89518eb5b5d9c839 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:13.064555 20799 tablet_server.cc:196] TabletServer@127.20.79.193:0 shutdown complete.
I20260812 06:18:13.092237 20799 master.cc:562] Master@127.20.79.254:36587 shutting down...
I20260812 06:18:13.095800 20799 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:13.095966 20799 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:13.096021 20799 tablet_replica.cc:333] T 00000000000000000000000000000000 P 39cb4725871b4026b3e9f90df6a9ca8e: stopping tablet replica
I20260812 06:18:13.108500 20799 master.cc:584] Master@127.20.79.254:36587 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5684 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:13.199256 20799 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.79.254:38217
I20260812 06:18:13.199640 20799 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:13.202214 20799 server_base.cc:1061] running on GCE node
W20260812 06:18:13.202342 21123 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:13.202239 21117 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:13.202423 21119 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:13.202775 20799 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:13.202850 20799 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:13.202888 20799 hybrid_clock.cc:648] HybridClock initialized: now 1786515493202887 us; error 0 us; skew 500 ppm
I20260812 06:18:13.204003 20799 webserver.cc:533] Webserver started at http://127.20.79.254:44799/ using document root <none> and password file <none>
I20260812 06:18:13.204246 20799 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:13.204311 20799 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:13.204382 20799 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:13.204895 20799 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/master-0-root/instance:
uuid: "fd8d76cbb8794c37971f7a153a04a0f3"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-h6n0"
I20260812 06:18:13.206866 20799 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:13.207875 21128 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.208189 20799 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:13.208279 20799 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/master-0-root
uuid: "fd8d76cbb8794c37971f7a153a04a0f3"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-h6n0"
I20260812 06:18:13.208331 20799 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:13.219971 20799 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:13.220458 20799 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:13.225992 20799 rpc_server.cc:307] RPC server started. Bound to: 127.20.79.254:38217
I20260812 06:18:13.226845 21223 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.79.254:38217 every 8 connection(s)
I20260812 06:18:13.229167 21224 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:13.242462 21224 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3: Bootstrap starting.
I20260812 06:18:13.243372 21224 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:13.244740 21224 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3: No bootstrap required, opened a new log
I20260812 06:18:13.245157 21224 raft_consensus.cc:359] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER }
I20260812 06:18:13.245276 21224 raft_consensus.cc:385] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:13.245321 21224 raft_consensus.cc:740] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fd8d76cbb8794c37971f7a153a04a0f3, State: Initialized, Role: FOLLOWER
I20260812 06:18:13.245803 21224 consensus_queue.cc:260] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [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: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER }
I20260812 06:18:13.245992 21224 raft_consensus.cc:399] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:13.246057 21224 raft_consensus.cc:493] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:13.246129 21224 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:13.247002 21224 raft_consensus.cc:515] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER }
I20260812 06:18:13.247169 21224 leader_election.cc:304] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [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: fd8d76cbb8794c37971f7a153a04a0f3; no voters: 
I20260812 06:18:13.247387 21224 leader_election.cc:290] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:13.247577 21230 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:13.247821 21230 raft_consensus.cc:697] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 1 LEADER]: Becoming Leader. State: Replica: fd8d76cbb8794c37971f7a153a04a0f3, State: Running, Role: LEADER
I20260812 06:18:13.247870 21224 sys_catalog.cc:565] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:13.247965 21230 consensus_queue.cc:237] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [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: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER }
I20260812 06:18:13.248441 21232 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader fd8d76cbb8794c37971f7a153a04a0f3. Latest consensus state: current_term: 1 leader_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER } }
I20260812 06:18:13.248427 21231 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd8d76cbb8794c37971f7a153a04a0f3" member_type: VOTER } }
I20260812 06:18:13.248581 21232 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:13.248659 21231 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:13.249205 21243 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:13.250003 21243 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:13.250435 20799 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:13.251925 21243 catalog_manager.cc:1383] Generated new cluster ID: facc9c593a7f4ec091cc7c0663f615df
I20260812 06:18:13.251993 21243 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:13.279381 21243 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:13.279930 21243 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:13.287530 21243 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3: Generated new TSK 0
I20260812 06:18:13.287708 21243 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:13.315361 20799 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:13.317471 21262 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:13.317582 21259 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:13.317607 20799 server_base.cc:1061] running on GCE node
W20260812 06:18:13.317577 21260 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:13.317907 20799 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:13.317960 20799 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:13.317976 20799 hybrid_clock.cc:648] HybridClock initialized: now 1786515493317976 us; error 0 us; skew 500 ppm
I20260812 06:18:13.318984 20799 webserver.cc:533] Webserver started at http://127.20.79.193:38969/ using document root <none> and password file <none>
I20260812 06:18:13.319180 20799 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:13.319253 20799 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:13.319447 20799 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:13.320062 20799 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/instance:
uuid: "f59c998719724f8d8246160f6313b2bd"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-h6n0"
I20260812 06:18:13.321877 20799 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:13.322928 21270 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.323220 20799 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:13.323469 20799 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root
uuid: "f59c998719724f8d8246160f6313b2bd"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-h6n0"
I20260812 06:18:13.323593 20799 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:13.332191 20799 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:13.332535 20799 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:13.332828 20799 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:13.333285 20799 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:13.333350 20799 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.333405 20799 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:13.333457 20799 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.338280 20799 rpc_server.cc:307] RPC server started. Bound to: 127.20.79.193:36839
I20260812 06:18:13.338316 21370 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.79.193:36839 every 8 connection(s)
I20260812 06:18:13.347697 21371 heartbeater.cc:344] Connected to a master server at 127.20.79.254:38217
I20260812 06:18:13.347806 21371 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:13.348079 21371 heartbeater.cc:507] Master 127.20.79.254:38217 requested a full tablet report, sending...
I20260812 06:18:13.348753 21159 ts_manager.cc:194] Registered new tserver with Master: f59c998719724f8d8246160f6313b2bd (127.20.79.193:36839)
I20260812 06:18:13.349059 20799 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01017816s
I20260812 06:18:13.349787 21159 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55640
I20260812 06:18:13.356694 21159 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55650:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:13.366842 21315 tablet_service.cc:1511] Processing CreateTablet for tablet 1dd42b2f124848ad8b6ae2e6eede7ec6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f36efd0f7ee246a39abca1eb7683c282]), partition=
I20260812 06:18:13.367085 21315 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1dd42b2f124848ad8b6ae2e6eede7ec6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:13.369180 21388 tablet_bootstrap.cc:492] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Bootstrap starting.
I20260812 06:18:13.370102 21388 tablet_bootstrap.cc:654] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:13.371719 21388 tablet_bootstrap.cc:492] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: No bootstrap required, opened a new log
I20260812 06:18:13.371850 21388 ts_tablet_manager.cc:1403] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:13.372282 21388 raft_consensus.cc:359] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f59c998719724f8d8246160f6313b2bd" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 36839 } }
I20260812 06:18:13.372397 21388 raft_consensus.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:13.372449 21388 raft_consensus.cc:740] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f59c998719724f8d8246160f6313b2bd, State: Initialized, Role: FOLLOWER
I20260812 06:18:13.372632 21388 consensus_queue.cc:260] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [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: "f59c998719724f8d8246160f6313b2bd" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 36839 } }
I20260812 06:18:13.372749 21388 raft_consensus.cc:399] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:13.372800 21388 raft_consensus.cc:493] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:13.372865 21388 raft_consensus.cc:3060] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:13.373663 21388 raft_consensus.cc:515] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f59c998719724f8d8246160f6313b2bd" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 36839 } }
I20260812 06:18:13.373834 21388 leader_election.cc:304] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [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: f59c998719724f8d8246160f6313b2bd; no voters: 
I20260812 06:18:13.374064 21388 leader_election.cc:290] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:13.374337 21390 raft_consensus.cc:2804] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:13.374444 21388 ts_tablet_manager.cc:1434] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:13.374493 21390 raft_consensus.cc:697] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 1 LEADER]: Becoming Leader. State: Replica: f59c998719724f8d8246160f6313b2bd, State: Running, Role: LEADER
I20260812 06:18:13.374471 21371 heartbeater.cc:499] Master 127.20.79.254:38217 was elected leader, sending a full tablet report...
I20260812 06:18:13.374699 21390 consensus_queue.cc:237] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [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: "f59c998719724f8d8246160f6313b2bd" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 36839 } }
I20260812 06:18:13.376053 21159 catalog_manager.cc:5719] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd reported cstate change: term changed from 0 to 1, leader changed from <none> to f59c998719724f8d8246160f6313b2bd (127.20.79.193). New cstate: current_term: 1 leader_uuid: "f59c998719724f8d8246160f6313b2bd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f59c998719724f8d8246160f6313b2bd" member_type: VOTER last_known_addr { host: "127.20.79.193" port: 36839 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:13.438009 20799 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.004s
I20260812 06:18:13.589485 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=19.054940
I20260812 06:18:13.739265 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.150s	user 0.101s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":655,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39379,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:13.740316 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): free 20743880 bytes of WAL
I20260812 06:18:13.740649 21277 log_reader.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6: removed 2 log segments from log reader
I20260812 06:18:13.740726 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000001 (ops 1-6)
I20260812 06:18:13.740780 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000002 (ops 7-11)
I20260812 06:18:13.744935 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:13.745472 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): 16411400 bytes on disk
I20260812 06:18:13.745980 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.746380 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:13.767015 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.020s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.767526 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:13.922461 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.155s	user 0.103s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":10422,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27961,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":402,"threads_started":5,"update_count":2000}
I20260812 06:18:13.923190 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:13.978837 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.055s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23934,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.979307 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:13.990899 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.991361 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:14.161851 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.170s	user 0.136s	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":305,"lbm_read_time_us":11518,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32291,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:18:14.162580 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:14.214277 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.052s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22235,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:14.214756 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:14.377250 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.162s	user 0.112s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":954,"lbm_read_time_us":11101,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29716,"lbm_writes_lt_1ms":443,"mutex_wait_us":375,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:18:14.378086 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:14.430874 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.053s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23775,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.431406 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:14.444572 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.444995 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:14.638456 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.193s	user 0.101s	sys 0.088s 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":639,"lbm_read_time_us":11678,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34222,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":91008,"update_count":2500}
I20260812 06:18:14.639112 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:14.695369 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.056s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.695822 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:14.708323 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.708874 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:14.878571 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.169s	user 0.117s	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":2000,"lbm_read_time_us":10411,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33508,"lbm_writes_lt_1ms":543,"mutex_wait_us":586,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":72960,"update_count":2500}
I20260812 06:18:14.879173 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=11.118625
I20260812 06:18:14.923034 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.044s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18827,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:14.923841 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:14.953198 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.029s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.953694 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:14.969144 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.969748 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:14.999749 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.030s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1161,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:15.000653 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): free 115943173 bytes of WAL
I20260812 06:18:15.001029 21277 log_reader.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6: removed 11 log segments from log reader
I20260812 06:18:15.001101 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000003 (ops 12-16)
I20260812 06:18:15.001142 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000004 (ops 17-21)
I20260812 06:18:15.001168 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000005 (ops 22-26)
I20260812 06:18:15.001190 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000006 (ops 27-31)
I20260812 06:18:15.001225 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000007 (ops 32-36)
I20260812 06:18:15.001253 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000008 (ops 37-41)
I20260812 06:18:15.001286 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000009 (ops 42-46)
I20260812 06:18:15.001320 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000010 (ops 47-51)
I20260812 06:18:15.001343 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000011 (ops 52-56)
I20260812 06:18:15.001371 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000012 (ops 57-61)
I20260812 06:18:15.001400 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000013 (ops 62-66)
I20260812 06:18:15.033355 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:15.033926 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.068509 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.034s	user 0.009s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.069248 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): 447 bytes on disk
I20260812 06:18:15.069823 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.070356 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.083374 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.083904 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:15.325448 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.241s	user 0.172s	sys 0.067s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1067,"lbm_read_time_us":16401,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43807,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:18:15.326107 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=15.087375
I20260812 06:18:15.377000 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.051s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":22488,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:15.377612 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.406213 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.028s	user 0.003s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6562,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.406716 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.417143 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.417565 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:15.623463 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.206s	user 0.150s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":291,"lbm_read_time_us":15007,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31563,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:15.624173 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:15.679370 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.055s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23340,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.679991 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.691001 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.691450 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:15.882122 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.191s	user 0.108s	sys 0.071s 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":1290,"lbm_read_time_us":11095,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32907,"lbm_writes_lt_1ms":543,"mutex_wait_us":426,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29056,"update_count":2500}
I20260812 06:18:15.882822 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:15.944703 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.062s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":26026,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.945461 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:15.958218 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.958844 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:16.153209 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.194s	user 0.145s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":718,"lbm_read_time_us":13277,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34320,"lbm_writes_lt_1ms":543,"mutex_wait_us":119,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:16.154040 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:16.215421 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.061s	user 0.028s	sys 0.030s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.216099 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:16.230513 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.231009 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:16.440662 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.209s	user 0.145s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1005,"lbm_read_time_us":14217,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34582,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.441246 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:16.515937 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.075s	user 0.036s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24003,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.516544 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:16.529461 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.530063 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:16.578361 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.048s	user 0.028s	sys 0.008s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:16.579430 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): free 116849516 bytes of WAL
I20260812 06:18:16.579774 21277 log_reader.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6: removed 12 log segments from log reader
I20260812 06:18:16.579829 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000014 (ops 67-71)
I20260812 06:18:16.579864 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000015 (ops 72-76)
I20260812 06:18:16.579881 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000016 (ops 77-80)
I20260812 06:18:16.579943 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000017 (ops 81-85)
I20260812 06:18:16.579994 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000018 (ops 86-90)
I20260812 06:18:16.580050 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000019 (ops 91-94)
I20260812 06:18:16.580099 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000020 (ops 95-99)
I20260812 06:18:16.580154 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000021 (ops 100-104)
I20260812 06:18:16.580199 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000022 (ops 105-109)
I20260812 06:18:16.580369 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000023 (ops 110-114)
I20260812 06:18:16.580431 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000024 (ops 115-118)
I20260812 06:18:16.580473 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000025 (ops 119-123)
I20260812 06:18:16.605526 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:16.606192 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): 447 bytes on disk
I20260812 06:18:16.606860 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.607523 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=3.181125
I20260812 06:18:16.623528 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.016s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:16.623976 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:16.636370 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:16.637606 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:16.885418 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.247s	user 0.153s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":824,"lbm_read_time_us":15525,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41638,"lbm_writes_lt_1ms":743,"mutex_wait_us":335,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:18:16.886178 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=18.063937
I20260812 06:18:16.958475 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.072s	user 0.045s	sys 0.012s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":26885,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.959034 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:16.970472 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.971405 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:17.180908 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.209s	user 0.153s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":664,"lbm_read_time_us":14878,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37160,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":3000}
I20260812 06:18:17.183162 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=15.087375
I20260812 06:18:17.235390 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.052s	user 0.021s	sys 0.029s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":24236,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:18:17.235903 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:17.259343 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.023s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5790,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.259779 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:17.270654 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.271147 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:17.482035 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.211s	user 0.130s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1014,"lbm_read_time_us":14001,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36313,"lbm_writes_lt_1ms":643,"mutex_wait_us":272,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:18:17.482681 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:17.545485 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.063s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22993,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.546011 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:17.556704 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.557192 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:17.735723 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.178s	user 0.099s	sys 0.074s 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":520,"lbm_read_time_us":12769,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30311,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:18:17.736647 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:17.790364 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.053s	user 0.038s	sys 0.010s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22973,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.790911 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:17.803231 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.803663 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:17.973752 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.170s	user 0.100s	sys 0.069s 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":284,"lbm_read_time_us":11671,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29281,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:18:17.974592 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=14.095187
I20260812 06:18:18.039261 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.062s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23148,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.040155 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:18.054139 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.054687 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:18.095855 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushMRSOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.041s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1147,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1461,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:18.096607 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): free 112239478 bytes of WAL
I20260812 06:18:18.096863 21277 log_reader.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6: removed 11 log segments from log reader
I20260812 06:18:18.096922 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000026 (ops 124-128)
I20260812 06:18:18.096958 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000027 (ops 129-133)
I20260812 06:18:18.096992 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000028 (ops 134-138)
I20260812 06:18:18.097028 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000029 (ops 139-142)
I20260812 06:18:18.097054 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000030 (ops 143-147)
I20260812 06:18:18.097085 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000031 (ops 148-152)
I20260812 06:18:18.097113 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000032 (ops 153-157)
I20260812 06:18:18.097142 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000033 (ops 158-162)
I20260812 06:18:18.097173 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000034 (ops 163-167)
I20260812 06:18:18.097206 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000035 (ops 168-172)
I20260812 06:18:18.097236 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000036 (ops 173-177)
I20260812 06:18:18.125227 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:18.125772 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): 463 bytes on disk
I20260812 06:18:18.126363 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: UndoDeltaBlockGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.126932 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:18.152669 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.026s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.153373 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6): free 12018006 bytes of WAL
I20260812 06:18:18.153680 21277 log_reader.cc:385] T 1dd42b2f124848ad8b6ae2e6eede7ec6: removed 1 log segments from log reader
I20260812 06:18:18.153759 21277 log.cc:1079] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: Deleting log segment in path: /tmp/dist-test-taskznUGO9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487503014-20799-0/minicluster-data/ts-0-root/wals/1dd42b2f124848ad8b6ae2e6eede7ec6/wal-000000037 (ops 178-182)
I20260812 06:18:18.156237 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: LogGCOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:18.156595 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:18.172889 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.173316 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:18.418747 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.245s	user 0.151s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979753,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":547,"lbm_read_time_us":17011,"lbm_reads_lt_1ms":766,"lbm_write_time_us":45475,"lbm_writes_lt_1ms":743,"mutex_wait_us":81,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:18:18.420408 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=18.063937
I20260812 06:18:18.491015 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.070s	user 0.037s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":34315,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:18:18.492345 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:18.520344 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.028s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.520929 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=2.188937
I20260812 06:18:18.534358 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: FlushDeltaMemStoresOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.534873 21372 maintenance_manager.cc:419] P f59c998719724f8d8246160f6313b2bd: Scheduling MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6): perf score=1.000000
I20260812 06:18:18.622586 20799 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.184s	user 1.872s	sys 0.205s
I20260812 06:18:18.706248 20799 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.000s
I20260812 06:18:18.706775 20799 tablet_server.cc:179] TabletServer@127.20.79.193:0 shutting down...
I20260812 06:18:18.723312 21277 maintenance_manager.cc:643] P f59c998719724f8d8246160f6313b2bd: MajorDeltaCompactionOp(1dd42b2f124848ad8b6ae2e6eede7ec6) complete. Timing: real 0.188s	user 0.158s	sys 0.030s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":237,"lbm_read_time_us":15084,"lbm_reads_lt_1ms":769,"lbm_write_time_us":39787,"lbm_writes_lt_1ms":743,"mutex_wait_us":53,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3500}
I20260812 06:18:18.723971 20799 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:18.724269 20799 tablet_replica.cc:333] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd: stopping tablet replica
I20260812 06:18:18.724478 20799 raft_consensus.cc:2243] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.724670 20799 raft_consensus.cc:2272] T 1dd42b2f124848ad8b6ae2e6eede7ec6 P f59c998719724f8d8246160f6313b2bd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.730654 20799 tablet_server.cc:196] TabletServer@127.20.79.193:0 shutdown complete.
I20260812 06:18:18.785219 20799 master.cc:562] Master@127.20.79.254:38217 shutting down...
I20260812 06:18:18.789674 20799 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.789870 20799 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.789951 20799 tablet_replica.cc:333] T 00000000000000000000000000000000 P fd8d76cbb8794c37971f7a153a04a0f3: stopping tablet replica
I20260812 06:18:18.803288 20799 master.cc:584] Master@127.20.79.254:38217 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5697 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11383 ms total)

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