[==========] 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:42.315088  3328 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.64.62:36321
I20260812 06:18:42.316172  3328 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:42.316820  3328 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:42.323642  3333 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:42.323657  3337 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:42.323805  3328 server_base.cc:1061] running on GCE node
W20260812 06:18:42.323958  3335 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:42.324515  3328 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:42.324654  3328 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:42.324692  3328 hybrid_clock.cc:648] HybridClock initialized: now 1786515522324690 us; error 0 us; skew 500 ppm
I20260812 06:18:42.326597  3328 webserver.cc:533] Webserver started at http://127.3.64.62:38775/ using document root <none> and password file <none>
I20260812 06:18:42.327134  3328 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:42.327196  3328 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:42.327396  3328 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:42.329018  3328 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/master-0-root/instance:
uuid: "5cfdbbdf2532407a826e6c5599e4d016"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-0kls"
I20260812 06:18:42.332518  3328 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:18:42.334591  3342 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:42.335598  3328 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:42.335732  3328 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/master-0-root
uuid: "5cfdbbdf2532407a826e6c5599e4d016"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-0kls"
I20260812 06:18:42.335846  3328 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-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:42.352789  3328 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:42.353478  3328 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:42.353685  3328 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:42.361030  3328 rpc_server.cc:307] RPC server started. Bound to: 127.3.64.62:36321
I20260812 06:18:42.361044  3402 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.64.62:36321 every 8 connection(s)
I20260812 06:18:42.363413  3403 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:42.368883  3403 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: Bootstrap starting.
I20260812 06:18:42.371232  3403 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:42.372166  3403 log.cc:826] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:42.373914  3403 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: No bootstrap required, opened a new log
I20260812 06:18:42.376652  3403 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER }
I20260812 06:18:42.376827  3403 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:42.376868  3403 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5cfdbbdf2532407a826e6c5599e4d016, State: Initialized, Role: FOLLOWER
I20260812 06:18:42.377440  3403 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [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: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER }
I20260812 06:18:42.377600  3403 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:42.377671  3403 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:42.377857  3403 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:42.378702  3403 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER }
I20260812 06:18:42.379153  3403 leader_election.cc:304] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [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: 5cfdbbdf2532407a826e6c5599e4d016; no voters: 
I20260812 06:18:42.379480  3403 leader_election.cc:290] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:42.379624  3406 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:42.379935  3406 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 1 LEADER]: Becoming Leader. State: Replica: 5cfdbbdf2532407a826e6c5599e4d016, State: Running, Role: LEADER
I20260812 06:18:42.380369  3406 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [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: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER }
I20260812 06:18:42.380505  3403 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:42.382282  3408 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5cfdbbdf2532407a826e6c5599e4d016. Latest consensus state: current_term: 1 leader_uuid: "5cfdbbdf2532407a826e6c5599e4d016" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER } }
I20260812 06:18:42.382320  3407 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5cfdbbdf2532407a826e6c5599e4d016" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5cfdbbdf2532407a826e6c5599e4d016" member_type: VOTER } }
I20260812 06:18:42.382409  3408 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:42.382414  3407 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:42.382803  3420 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:42.383004  3328 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:42.385075  3420 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:42.389974  3420 catalog_manager.cc:1383] Generated new cluster ID: b5a7fb4529404c85923967c103c0ed19
I20260812 06:18:42.390055  3420 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:42.398759  3420 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:42.399935  3420 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:42.408593  3420 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: Generated new TSK 0
I20260812 06:18:42.409283  3420 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:42.415591  3328 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:42.418740  3428 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:42.418883  3328 server_base.cc:1061] running on GCE node
W20260812 06:18:42.418782  3429 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:42.418807  3431 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:42.419230  3328 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:42.419298  3328 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:42.419322  3328 hybrid_clock.cc:648] HybridClock initialized: now 1786515522419322 us; error 0 us; skew 500 ppm
I20260812 06:18:42.420236  3328 webserver.cc:533] Webserver started at http://127.3.64.1:40161/ using document root <none> and password file <none>
I20260812 06:18:42.420404  3328 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:42.420451  3328 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:42.420526  3328 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:42.420972  3328 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/instance:
uuid: "f0d0d3242f0b40aa8afb203edae06773"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-0kls"
I20260812 06:18:42.422808  3328 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:42.423980  3436 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:42.424309  3328 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:42.424376  3328 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root
uuid: "f0d0d3242f0b40aa8afb203edae06773"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-0kls"
I20260812 06:18:42.424466  3328 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-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:42.430763  3328 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:42.431212  3328 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:42.431730  3328 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:42.432567  3328 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:42.432618  3328 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.432688  3328 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:42.432731  3328 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.439754  3328 rpc_server.cc:307] RPC server started. Bound to: 127.3.64.1:39675
I20260812 06:18:42.439795  3505 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.64.1:39675 every 8 connection(s)
I20260812 06:18:42.449661  3506 heartbeater.cc:344] Connected to a master server at 127.3.64.62:36321
I20260812 06:18:42.449945  3506 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:42.450392  3506 heartbeater.cc:507] Master 127.3.64.62:36321 requested a full tablet report, sending...
I20260812 06:18:42.451941  3362 ts_manager.cc:194] Registered new tserver with Master: f0d0d3242f0b40aa8afb203edae06773 (127.3.64.1:39675)
I20260812 06:18:42.452008  3328 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01156509s
I20260812 06:18:42.453533  3362 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33842
I20260812 06:18:42.463377  3362 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33844:
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:42.479405  3470 tablet_service.cc:1511] Processing CreateTablet for tablet f4ebb1ee85ef44388bec8a2fa8658680 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a9fb29059d8f493993bd5f42efe41664]), partition=
I20260812 06:18:42.479905  3470 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f4ebb1ee85ef44388bec8a2fa8658680. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:42.482302  3519 tablet_bootstrap.cc:492] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Bootstrap starting.
I20260812 06:18:42.483376  3519 tablet_bootstrap.cc:654] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:42.484469  3519 tablet_bootstrap.cc:492] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: No bootstrap required, opened a new log
I20260812 06:18:42.484601  3519 ts_tablet_manager.cc:1403] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:42.485030  3519 raft_consensus.cc:359] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0d0d3242f0b40aa8afb203edae06773" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 39675 } }
I20260812 06:18:42.485159  3519 raft_consensus.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:42.485229  3519 raft_consensus.cc:740] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f0d0d3242f0b40aa8afb203edae06773, State: Initialized, Role: FOLLOWER
I20260812 06:18:42.485410  3519 consensus_queue.cc:260] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [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: "f0d0d3242f0b40aa8afb203edae06773" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 39675 } }
I20260812 06:18:42.485536  3519 raft_consensus.cc:399] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:42.485586  3519 raft_consensus.cc:493] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:42.485641  3519 raft_consensus.cc:3060] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:42.486550  3519 raft_consensus.cc:515] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0d0d3242f0b40aa8afb203edae06773" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 39675 } }
I20260812 06:18:42.486757  3519 leader_election.cc:304] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [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: f0d0d3242f0b40aa8afb203edae06773; no voters: 
I20260812 06:18:42.487021  3519 leader_election.cc:290] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:42.487119  3522 raft_consensus.cc:2804] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:42.487309  3522 raft_consensus.cc:697] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 1 LEADER]: Becoming Leader. State: Replica: f0d0d3242f0b40aa8afb203edae06773, State: Running, Role: LEADER
I20260812 06:18:42.487412  3519 ts_tablet_manager.cc:1434] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:42.487552  3522 consensus_queue.cc:237] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [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: "f0d0d3242f0b40aa8afb203edae06773" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 39675 } }
I20260812 06:18:42.487721  3506 heartbeater.cc:499] Master 127.3.64.62:36321 was elected leader, sending a full tablet report...
I20260812 06:18:42.490315  3362 catalog_manager.cc:5719] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 reported cstate change: term changed from 0 to 1, leader changed from <none> to f0d0d3242f0b40aa8afb203edae06773 (127.3.64.1). New cstate: current_term: 1 leader_uuid: "f0d0d3242f0b40aa8afb203edae06773" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f0d0d3242f0b40aa8afb203edae06773" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 39675 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:42.558440  3328 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.016s	sys 0.010s
I20260812 06:18:42.691289  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=15.086190
I20260812 06:18:42.871512  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.180s	user 0.126s	sys 0.041s Metrics: {"bytes_written":14809964,"cfile_init":1,"compiler_manager_pool.queue_time_us":209,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":919,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43135,"lbm_writes_lt_1ms":728,"mutex_wait_us":4171,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":117888,"thread_start_us":132,"threads_started":1,"update_count":1805}
I20260812 06:18:42.872828  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680): free 20743880 bytes of WAL
I20260812 06:18:42.873162  3441 log_reader.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680: removed 2 log segments from log reader
I20260812 06:18:42.873235  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000001 (ops 1-6)
I20260812 06:18:42.873349  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000002 (ops 7-11)
I20260812 06:18:42.879236  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:42.879803  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=4.173312
I20260812 06:18:42.904438  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.024s	user 0.007s	sys 0.013s Metrics: {"bytes_written":5292372,"delete_count":0,"lbm_write_time_us":7451,"lbm_writes_lt_1ms":132,"reinsert_count":0,"update_count":645}
I20260812 06:18:42.904995  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680): 12719217 bytes on disk
I20260812 06:18:42.906352  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.906802  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:43.099331  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.192s	user 0.112s	sys 0.073s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364458,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1000,"lbm_read_time_us":12905,"lbm_reads_lt_1ms":550,"lbm_write_time_us":30241,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":322,"threads_started":5,"update_count":2450}
I20260812 06:18:43.099948  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:43.152973  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.053s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20901,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.153556  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:43.166064  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.166553  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:43.332912  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.166s	user 0.120s	sys 0.039s 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":420,"lbm_read_time_us":10014,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32481,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:43.333400  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:43.388864  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.055s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23858,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.389369  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:43.406659  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.407276  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:43.553985  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.147s	user 0.101s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":995,"lbm_read_time_us":8691,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30058,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:18:43.554751  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:43.605063  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.050s	user 0.028s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22514,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.605659  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:43.628273  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.022s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.628798  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:43.785454  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.156s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":10655,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29787,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:18:43.786164  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:43.836939  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.051s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22019,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.837554  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:43.850323  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.850896  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:44.014560  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.163s	user 0.122s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":9289,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31138,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:18:44.015295  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:44.066447  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.051s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21713,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.067051  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:44.105010  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.038s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":314,"dirs.run_wall_time_us":1511,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1911,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:44.106065  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680): 462 bytes on disk
I20260812 06:18:44.106582  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:44.107066  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=3.181125
I20260812 06:18:44.120606  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:44.121161  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680): free 112239274 bytes of WAL
I20260812 06:18:44.121430  3441 log_reader.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680: removed 11 log segments from log reader
I20260812 06:18:44.121490  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000003 (ops 12-16)
I20260812 06:18:44.121529  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000004 (ops 17-21)
I20260812 06:18:44.121562  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000005 (ops 22-26)
I20260812 06:18:44.121592  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000006 (ops 27-30)
I20260812 06:18:44.121618  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000007 (ops 31-35)
I20260812 06:18:44.121657  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000008 (ops 36-40)
I20260812 06:18:44.121680  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000009 (ops 41-45)
I20260812 06:18:44.121711  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000010 (ops 46-50)
I20260812 06:18:44.121745  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000011 (ops 51-55)
I20260812 06:18:44.121773  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000012 (ops 56-60)
I20260812 06:18:44.121822  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000013 (ops 61-65)
I20260812 06:18:44.151337  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:44.151953  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:44.178851  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.027s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:44.179487  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:44.193451  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.193992  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:44.410705  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.216s	user 0.151s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":587,"lbm_read_time_us":14468,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38803,"lbm_writes_lt_1ms":743,"mutex_wait_us":281,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:18:44.411242  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=15.087375
I20260812 06:18:44.479758  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.068s	user 0.024s	sys 0.034s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":26944,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:18:44.480283  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=6.157687
I20260812 06:18:44.504971  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.024s	user 0.018s	sys 0.000s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8688,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:44.505664  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:44.678237  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.172s	user 0.137s	sys 0.035s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":12220,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35530,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:18:44.682214  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:44.724946  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.042s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19573,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.725759  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:44.739466  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.013s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.740233  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:44.903596  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.163s	user 0.109s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":457,"lbm_read_time_us":8978,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31036,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:18:44.904258  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:44.953963  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.050s	user 0.046s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21587,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.954420  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:45.104395  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.150s	user 0.097s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":204,"lbm_read_time_us":8967,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23780,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.105072  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:45.152272  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.047s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20895,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.152947  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:45.169067  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.169725  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:45.355852  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.186s	user 0.123s	sys 0.053s 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":375,"lbm_read_time_us":12297,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29615,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:45.356488  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:45.407394  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.051s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22057,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.407954  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:45.420194  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.420732  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:45.578904  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.158s	user 0.113s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1382,"lbm_read_time_us":11963,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30760,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:18:45.579820  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=10.126437
I20260812 06:18:45.616711  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16234,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.617326  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:45.634290  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.634924  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:45.664794  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.030s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1554,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1920}
I20260812 06:18:45.665570  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680): free 133024419 bytes of WAL
I20260812 06:18:45.665908  3441 log_reader.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680: removed 13 log segments from log reader
I20260812 06:18:45.665997  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000014 (ops 66-70)
I20260812 06:18:45.666064  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000015 (ops 71-74)
I20260812 06:18:45.666113  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000016 (ops 75-79)
I20260812 06:18:45.666145  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000017 (ops 80-84)
I20260812 06:18:45.666183  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000018 (ops 85-89)
I20260812 06:18:45.666224  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000019 (ops 90-94)
I20260812 06:18:45.666285  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000020 (ops 95-99)
I20260812 06:18:45.666326  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000021 (ops 100-104)
I20260812 06:18:45.666364  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000022 (ops 105-109)
I20260812 06:18:45.666400  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000023 (ops 110-114)
I20260812 06:18:45.666436  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000024 (ops 115-119)
I20260812 06:18:45.666472  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000025 (ops 120-124)
I20260812 06:18:45.666508  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000026 (ops 125-129)
I20260812 06:18:45.700640  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.035s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:18:45.701205  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=4.173312
I20260812 06:18:45.720031  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":5866705,"delete_count":0,"lbm_write_time_us":7735,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:18:45.720521  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680): 491 bytes on disk
I20260812 06:18:45.720959  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680) 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:45.721459  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.196750
I20260812 06:18:45.730132  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":2815,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:18:45.730589  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680): free 12017954 bytes of WAL
I20260812 06:18:45.730801  3441 log_reader.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680: removed 1 log segments from log reader
I20260812 06:18:45.730844  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000027 (ops 130-134)
I20260812 06:18:45.733772  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:45.734148  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:45.929306  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.195s	user 0.134s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877298,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":552,"lbm_read_time_us":12604,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34246,"lbm_writes_lt_1ms":643,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":86656,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:45.932000  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:45.983494  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22923,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:45.984059  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:45.996348  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.996780  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:46.194016  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.197s	user 0.138s	sys 0.049s 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":748,"lbm_read_time_us":12248,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30669,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:18:46.194680  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:46.265851  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.071s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":46510,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.266445  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:46.280177  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.280736  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:46.430925  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.150s	user 0.105s	sys 0.039s 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":352,"lbm_read_time_us":9820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28354,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:46.433765  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:46.489140  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.055s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25380,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.489682  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:46.500617  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.501194  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:46.650730  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.149s	user 0.099s	sys 0.048s 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":177,"lbm_read_time_us":11774,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31139,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:46.651341  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=11.118625
I20260812 06:18:46.689007  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16899,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:46.689754  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:46.707895  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5909,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.708513  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:46.833855  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.125s	user 0.102s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":85,"lbm_read_time_us":7299,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25667,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:18:46.835033  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=10.126437
I20260812 06:18:46.879345  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19769,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.879949  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:46.892145  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.892622  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:47.029771  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.137s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":742,"lbm_read_time_us":9773,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26299,"lbm_writes_lt_1ms":443,"mutex_wait_us":391,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:18:47.030534  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=11.118625
I20260812 06:18:47.075136  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.044s	user 0.025s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15503,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:47.075722  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:47.085963  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.086783  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:47.124339  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushMRSOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.037s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":154,"dirs.run_wall_time_us":1534,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2048,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:47.124998  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680): free 108988750 bytes of WAL
I20260812 06:18:47.125249  3441 log_reader.cc:385] T f4ebb1ee85ef44388bec8a2fa8658680: removed 11 log segments from log reader
I20260812 06:18:47.125291  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000028 (ops 135-139)
I20260812 06:18:47.125322  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000029 (ops 140-144)
I20260812 06:18:47.125387  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000030 (ops 145-149)
I20260812 06:18:47.125422  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000031 (ops 150-154)
I20260812 06:18:47.125487  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000032 (ops 155-159)
I20260812 06:18:47.125535  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000033 (ops 160-164)
I20260812 06:18:47.125573  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000034 (ops 165-168)
I20260812 06:18:47.125610  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000035 (ops 169-173)
I20260812 06:18:47.125649  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000036 (ops 174-178)
I20260812 06:18:47.125689  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000037 (ops 179-183)
I20260812 06:18:47.125727  3441 log.cc:1079] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/f4ebb1ee85ef44388bec8a2fa8658680/wal-000000038 (ops 184-188)
I20260812 06:18:47.149770  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: LogGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.025s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:18:47.150442  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:47.167965  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.017s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.168463  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680): 447 bytes on disk
I20260812 06:18:47.168973  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: UndoDeltaBlockGCOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.169513  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:47.184744  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.185472  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:47.381309  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.196s	user 0.134s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3110,"lbm_read_time_us":15031,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30947,"lbm_writes_lt_1ms":643,"mutex_wait_us":2555,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:18:47.382194  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=14.095187
I20260812 06:18:47.434623  3328 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.876s	user 1.796s	sys 0.123s
I20260812 06:18:47.437758  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.055s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.438333  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=2.188937
I20260812 06:18:47.454515  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: FlushDeltaMemStoresOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:18:47.454983  3507 maintenance_manager.cc:419] P f0d0d3242f0b40aa8afb203edae06773: Scheduling MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680): perf score=1.000000
I20260812 06:18:47.503307  3328 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.002s	sys 0.000s
I20260812 06:18:47.504037  3328 tablet_server.cc:179] TabletServer@127.3.64.1:0 shutting down...
I20260812 06:18:47.584298  3441 maintenance_manager.cc:643] P f0d0d3242f0b40aa8afb203edae06773: MajorDeltaCompactionOp(f4ebb1ee85ef44388bec8a2fa8658680) complete. Timing: real 0.129s	user 0.085s	sys 0.044s Metrics: {"cfile_cache_hit":252,"cfile_cache_hit_bytes":10299130,"cfile_cache_miss":280,"cfile_cache_miss_bytes":14475560,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":6705,"lbm_reads_lt_1ms":312,"lbm_write_time_us":25518,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":138240,"update_count":2500}
I20260812 06:18:47.585140  3328 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:47.585580  3328 tablet_replica.cc:333] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773: stopping tablet replica
I20260812 06:18:47.585889  3328 raft_consensus.cc:2243] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:47.586138  3328 raft_consensus.cc:2272] T f4ebb1ee85ef44388bec8a2fa8658680 P f0d0d3242f0b40aa8afb203edae06773 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:47.601678  3328 tablet_server.cc:196] TabletServer@127.3.64.1:0 shutdown complete.
I20260812 06:18:47.632318  3328 master.cc:562] Master@127.3.64.62:36321 shutting down...
I20260812 06:18:47.636291  3328 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:47.636458  3328 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:47.636514  3328 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5cfdbbdf2532407a826e6c5599e4d016: stopping tablet replica
I20260812 06:18:47.649019  3328 master.cc:584] Master@127.3.64.62:36321 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5429 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:47.756373  3328 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.64.62:42963
I20260812 06:18:47.756839  3328 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:47.759243  3328 server_base.cc:1061] running on GCE node
W20260812 06:18:47.759294  3544 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:47.759348  3542 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:47.759347  3541 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:47.759639  3328 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.759680  3328 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:47.759696  3328 hybrid_clock.cc:648] HybridClock initialized: now 1786515527759695 us; error 0 us; skew 500 ppm
I20260812 06:18:47.760529  3328 webserver.cc:533] Webserver started at http://127.3.64.62:39339/ using document root <none> and password file <none>
I20260812 06:18:47.760710  3328 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.760766  3328 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.760866  3328 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.761273  3328 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/master-0-root/instance:
uuid: "103ed782bb88477a8c639f3678fa1dc4"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-0kls"
I20260812 06:18:47.762902  3328 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:47.763834  3551 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:47.764086  3328 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:47.764176  3328 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/master-0-root
uuid: "103ed782bb88477a8c639f3678fa1dc4"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-0kls"
I20260812 06:18:47.764266  3328 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-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:47.785760  3328 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.786331  3328 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.790763  3328 rpc_server.cc:307] RPC server started. Bound to: 127.3.64.62:42963
I20260812 06:18:47.793002  3611 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.64.62:42963 every 8 connection(s)
I20260812 06:18:47.793509  3612 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:47.795423  3612 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4: Bootstrap starting.
I20260812 06:18:47.796273  3612 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.797322  3612 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4: No bootstrap required, opened a new log
I20260812 06:18:47.797741  3612 raft_consensus.cc:359] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER }
I20260812 06:18:47.797878  3612 raft_consensus.cc:385] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.797933  3612 raft_consensus.cc:740] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 103ed782bb88477a8c639f3678fa1dc4, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.798094  3612 consensus_queue.cc:260] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [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: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER }
I20260812 06:18:47.798187  3612 raft_consensus.cc:399] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.798235  3612 raft_consensus.cc:493] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.798295  3612 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.798995  3612 raft_consensus.cc:515] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER }
I20260812 06:18:47.799180  3612 leader_election.cc:304] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [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: 103ed782bb88477a8c639f3678fa1dc4; no voters: 
I20260812 06:18:47.799383  3612 leader_election.cc:290] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.799511  3615 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.799741  3615 raft_consensus.cc:697] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 1 LEADER]: Becoming Leader. State: Replica: 103ed782bb88477a8c639f3678fa1dc4, State: Running, Role: LEADER
I20260812 06:18:47.799907  3612 sys_catalog.cc:565] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:47.799916  3615 consensus_queue.cc:237] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [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: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER }
I20260812 06:18:47.800426  3616 sys_catalog.cc:455] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "103ed782bb88477a8c639f3678fa1dc4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER } }
I20260812 06:18:47.800457  3617 sys_catalog.cc:455] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 103ed782bb88477a8c639f3678fa1dc4. Latest consensus state: current_term: 1 leader_uuid: "103ed782bb88477a8c639f3678fa1dc4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "103ed782bb88477a8c639f3678fa1dc4" member_type: VOTER } }
I20260812 06:18:47.800611  3617 sys_catalog.cc:458] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.800594  3616 sys_catalog.cc:458] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.801101  3623 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:47.802095  3623 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:47.802326  3328 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:47.804018  3623 catalog_manager.cc:1383] Generated new cluster ID: 2c2116eb90e54d0ea1fed904d451e778
I20260812 06:18:47.804076  3623 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:47.829723  3623 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:47.830382  3623 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:47.836005  3623 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4: Generated new TSK 0
I20260812 06:18:47.836199  3623 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:47.867172  3328 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:47.869426  3636 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:47.869527  3639 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:47.869535  3328 server_base.cc:1061] running on GCE node
W20260812 06:18:47.869441  3635 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:47.869940  3328 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.869987  3328 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:47.870003  3328 hybrid_clock.cc:648] HybridClock initialized: now 1786515527870004 us; error 0 us; skew 500 ppm
I20260812 06:18:47.870841  3328 webserver.cc:533] Webserver started at http://127.3.64.1:39513/ using document root <none> and password file <none>
I20260812 06:18:47.871024  3328 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.871071  3328 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.871181  3328 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.871595  3328 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/instance:
uuid: "6b11e023fe934754bce058110230bd6c"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-0kls"
I20260812 06:18:47.873104  3328 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:47.874073  3644 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:47.874351  3328 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:47.874426  3328 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root
uuid: "6b11e023fe934754bce058110230bd6c"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-0kls"
I20260812 06:18:47.874483  3328 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-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:47.889638  3328 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.890084  3328 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.890375  3328 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:47.890905  3328 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:47.890945  3328 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.891018  3328 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:47.891064  3328 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.895452  3328 rpc_server.cc:307] RPC server started. Bound to: 127.3.64.1:36957
I20260812 06:18:47.896123  3719 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.64.1:36957 every 8 connection(s)
I20260812 06:18:47.905251  3720 heartbeater.cc:344] Connected to a master server at 127.3.64.62:42963
I20260812 06:18:47.905370  3720 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:47.905633  3720 heartbeater.cc:507] Master 127.3.64.62:42963 requested a full tablet report, sending...
I20260812 06:18:47.906410  3569 ts_manager.cc:194] Registered new tserver with Master: 6b11e023fe934754bce058110230bd6c (127.3.64.1:36957)
I20260812 06:18:47.907172  3569 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53708
I20260812 06:18:47.907336  3328 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011070884s
I20260812 06:18:47.914410  3569 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53716:
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:47.923141  3675 tablet_service.cc:1511] Processing CreateTablet for tablet 51db9c2438f647989d4e08c91c751e1f (DEFAULT_TABLE table=heavy-update-compaction-test [id=9c5b4a4c1b654df285a80517468e0bdf]), partition=
I20260812 06:18:47.923426  3675 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 51db9c2438f647989d4e08c91c751e1f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:47.925374  3736 tablet_bootstrap.cc:492] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Bootstrap starting.
I20260812 06:18:47.926244  3736 tablet_bootstrap.cc:654] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.927230  3736 tablet_bootstrap.cc:492] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: No bootstrap required, opened a new log
I20260812 06:18:47.927345  3736 ts_tablet_manager.cc:1403] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:47.927739  3736 raft_consensus.cc:359] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b11e023fe934754bce058110230bd6c" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 36957 } }
I20260812 06:18:47.927868  3736 raft_consensus.cc:385] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.927915  3736 raft_consensus.cc:740] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6b11e023fe934754bce058110230bd6c, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.928061  3736 consensus_queue.cc:260] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [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: "6b11e023fe934754bce058110230bd6c" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 36957 } }
I20260812 06:18:47.928156  3736 raft_consensus.cc:399] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.928207  3736 raft_consensus.cc:493] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.928260  3736 raft_consensus.cc:3060] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.929132  3736 raft_consensus.cc:515] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b11e023fe934754bce058110230bd6c" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 36957 } }
I20260812 06:18:47.929296  3736 leader_election.cc:304] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [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: 6b11e023fe934754bce058110230bd6c; no voters: 
I20260812 06:18:47.929513  3736 leader_election.cc:290] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.929639  3738 raft_consensus.cc:2804] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.929908  3720 heartbeater.cc:499] Master 127.3.64.62:42963 was elected leader, sending a full tablet report...
I20260812 06:18:47.929924  3738 raft_consensus.cc:697] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 1 LEADER]: Becoming Leader. State: Replica: 6b11e023fe934754bce058110230bd6c, State: Running, Role: LEADER
I20260812 06:18:47.930090  3738 consensus_queue.cc:237] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [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: "6b11e023fe934754bce058110230bd6c" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 36957 } }
I20260812 06:18:47.930240  3736 ts_tablet_manager.cc:1434] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:47.931473  3569 catalog_manager.cc:5719] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c reported cstate change: term changed from 0 to 1, leader changed from <none> to 6b11e023fe934754bce058110230bd6c (127.3.64.1). New cstate: current_term: 1 leader_uuid: "6b11e023fe934754bce058110230bd6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b11e023fe934754bce058110230bd6c" member_type: VOTER last_known_addr { host: "127.3.64.1" port: 36957 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:47.992939  3328 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.008s
I20260812 06:18:48.146759  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushMRSOp(51db9c2438f647989d4e08c91c751e1f): perf score=19.054940
I20260812 06:18:48.296523  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushMRSOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.150s	user 0.125s	sys 0.021s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1025,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39398,"lbm_writes_lt_1ms":767,"mutex_wait_us":1357,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":19712,"update_count":1500}
I20260812 06:18:48.297688  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 20743831 bytes of WAL
I20260812 06:18:48.298012  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 2 log segments from log reader
I20260812 06:18:48.298138  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000001 (ops 1-6)
I20260812 06:18:48.298228  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000002 (ops 7-11)
I20260812 06:18:48.303732  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:48.311764  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f): 16821650 bytes on disk
I20260812 06:18:48.312525  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:48.312978  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:48.326742  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5055,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:18:48.327190  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:48.490443  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.163s	user 0.104s	sys 0.054s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20344048,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":507,"lbm_read_time_us":11463,"lbm_reads_lt_1ms":451,"lbm_write_time_us":22761,"lbm_writes_lt_1ms":434,"peak_mem_usage":49279629,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":326,"threads_started":5,"update_count":1955}
I20260812 06:18:48.491107  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:48.542447  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.051s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16368880,"delete_count":0,"lbm_write_time_us":25000,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":1995}
I20260812 06:18:48.542887  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:48.558240  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.558707  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:48.743997  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.185s	user 0.135s	sys 0.040s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774662,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":734,"lbm_read_time_us":11157,"lbm_reads_lt_1ms":563,"lbm_write_time_us":36039,"lbm_writes_lt_1ms":542,"mutex_wait_us":32,"peak_mem_usage":63074865,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2495}
I20260812 06:18:48.744590  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:48.797168  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.052s	user 0.035s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20139,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.797719  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:48.809670  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.810226  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:48.976877  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.166s	user 0.127s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":12679,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31446,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":198912,"update_count":2500}
I20260812 06:18:48.977490  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:49.029577  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.052s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.030303  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:49.041703  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.042341  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:49.221405  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.179s	user 0.144s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":507,"lbm_read_time_us":12537,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33251,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1560832,"update_count":2500}
I20260812 06:18:49.222491  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=13.103000
I20260812 06:18:49.265188  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.042s	user 0.021s	sys 0.016s Metrics: {"bytes_written":14604843,"delete_count":0,"lbm_write_time_us":18324,"lbm_writes_lt_1ms":359,"reinsert_count":0,"update_count":1780}
I20260812 06:18:49.265834  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.196750
I20260812 06:18:49.287415  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.021s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2215508,"delete_count":0,"lbm_write_time_us":3677,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:18:49.287880  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:49.297539  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.298041  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:49.486375  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.188s	user 0.098s	sys 0.086s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":408,"lbm_read_time_us":13549,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31148,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:18:49.487051  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:49.546655  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.059s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27063,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.547206  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:49.558085  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.558544  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushMRSOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:49.589737  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushMRSOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1614,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1929,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":3456}
I20260812 06:18:49.590487  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 115943237 bytes of WAL
I20260812 06:18:49.590734  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 11 log segments from log reader
I20260812 06:18:49.590777  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000003 (ops 12-16)
I20260812 06:18:49.590808  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000004 (ops 17-21)
I20260812 06:18:49.590875  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000005 (ops 22-26)
I20260812 06:18:49.590920  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000006 (ops 27-31)
I20260812 06:18:49.590960  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000007 (ops 32-36)
I20260812 06:18:49.591024  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000008 (ops 37-41)
I20260812 06:18:49.591060  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000009 (ops 42-46)
I20260812 06:18:49.591099  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000010 (ops 47-51)
I20260812 06:18:49.591140  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000011 (ops 52-56)
I20260812 06:18:49.591180  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000012 (ops 57-61)
I20260812 06:18:49.591221  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000013 (ops 62-66)
I20260812 06:18:49.617300  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:49.617712  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f): 447 bytes on disk
I20260812 06:18:49.618221  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:49.618729  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=3.181125
I20260812 06:18:49.636401  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4677001,"delete_count":0,"lbm_write_time_us":7321,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:18:49.636835  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:49.645638  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3380,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:18:49.646286  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:49.880120  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.234s	user 0.134s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":768,"lbm_read_time_us":16465,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39299,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:49.881512  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=18.063937
I20260812 06:18:49.948495  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.067s	user 0.037s	sys 0.027s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":29701,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:49.949188  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:49.962328  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.962949  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:50.135707  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.173s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1433,"lbm_read_time_us":12530,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36895,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:18:50.136684  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:50.197557  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.060s	user 0.030s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28114,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.198088  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:50.218559  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.020s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:18:50.219043  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:50.230464  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.231169  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:50.419135  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.188s	user 0.156s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":959,"lbm_read_time_us":14782,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38642,"lbm_writes_lt_1ms":643,"mutex_wait_us":256,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":3000}
I20260812 06:18:50.419725  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:50.468056  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.048s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21104,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.468715  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:50.485502  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.486073  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:50.649724  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.163s	user 0.126s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":598,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32550,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:18:50.650573  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:50.696971  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.046s	user 0.020s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20524,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.697518  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:50.859422  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.162s	user 0.116s	sys 0.035s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":208,"lbm_read_time_us":10229,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25987,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2000}
I20260812 06:18:50.860280  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:50.912436  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.052s	user 0.010s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20289,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.913019  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:50.924752  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.925276  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushMRSOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:50.962198  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushMRSOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.037s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1286,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1684,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:50.962831  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 112692376 bytes of WAL
I20260812 06:18:50.963055  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 11 log segments from log reader
I20260812 06:18:50.963115  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000014 (ops 67-71)
I20260812 06:18:50.963183  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000015 (ops 72-76)
I20260812 06:18:50.963224  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000016 (ops 77-81)
I20260812 06:18:50.963263  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000017 (ops 82-86)
I20260812 06:18:50.963301  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000018 (ops 87-91)
I20260812 06:18:50.963338  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000019 (ops 92-96)
I20260812 06:18:50.963376  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000020 (ops 97-101)
I20260812 06:18:50.963414  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000021 (ops 102-106)
I20260812 06:18:50.963450  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000022 (ops 107-111)
I20260812 06:18:50.963488  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000023 (ops 112-116)
I20260812 06:18:50.963526  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000024 (ops 117-121)
I20260812 06:18:50.987706  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:50.988155  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:51.008121  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.020s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.008668  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 12017930 bytes of WAL
I20260812 06:18:51.008931  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 1 log segments from log reader
I20260812 06:18:51.008992  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000025 (ops 122-126)
I20260812 06:18:51.011485  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:51.011858  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f): 447 bytes on disk
I20260812 06:18:51.012333  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:51.012833  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:51.025172  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.025626  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:51.273458  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.248s	user 0.163s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":701,"lbm_read_time_us":15991,"lbm_reads_lt_1ms":766,"lbm_write_time_us":37865,"lbm_writes_lt_1ms":743,"mutex_wait_us":36,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22912,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:18:51.274286  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=18.063937
I20260812 06:18:51.333931  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.059s	user 0.035s	sys 0.023s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26598,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:51.334438  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:51.514230  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.180s	user 0.119s	sys 0.060s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815567,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":361,"lbm_read_time_us":12878,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28601,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:51.514732  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:51.573242  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.058s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20534,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.573987  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:51.585357  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.585952  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:51.769320  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.183s	user 0.114s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":846,"dirs.run_cpu_time_us":774,"dirs.run_wall_time_us":4418,"lbm_read_time_us":13140,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28978,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:51.770123  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:51.834837  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.064s	user 0.040s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23733,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.835570  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:51.847358  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s 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:51.847985  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:52.046031  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.198s	user 0.137s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":11807,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34928,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:52.046623  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:52.109203  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.062s	user 0.024s	sys 0.034s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26311,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.109896  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:52.124033  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.124581  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:52.320042  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.195s	user 0.127s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":364,"lbm_read_time_us":12206,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30017,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:52.320689  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:52.370452  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.050s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23482,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.371049  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:52.387496  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.388422  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:52.557945  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.169s	user 0.124s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":10573,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30199,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:18:52.558519  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=14.095187
I20260812 06:18:52.608395  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.050s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.608984  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=2.188937
I20260812 06:18:52.620378  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.620918  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushMRSOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:52.654366  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushMRSOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.033s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1505,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1618,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:52.655056  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 121006684 bytes of WAL
I20260812 06:18:52.655303  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 12 log segments from log reader
I20260812 06:18:52.655346  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000026 (ops 127-131)
I20260812 06:18:52.655395  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000027 (ops 132-136)
I20260812 06:18:52.655438  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000028 (ops 137-141)
I20260812 06:18:52.655499  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000029 (ops 142-146)
I20260812 06:18:52.655539  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000030 (ops 147-151)
I20260812 06:18:52.655579  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000031 (ops 152-156)
I20260812 06:18:52.655620  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000032 (ops 157-161)
I20260812 06:18:52.655658  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000033 (ops 162-166)
I20260812 06:18:52.655697  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000034 (ops 167-170)
I20260812 06:18:52.655735  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000035 (ops 171-175)
I20260812 06:18:52.655772  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000036 (ops 176-180)
I20260812 06:18:52.655814  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000037 (ops 181-185)
I20260812 06:18:52.684326  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:52.684839  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f): 493 bytes on disk
I20260812 06:18:52.685428  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: UndoDeltaBlockGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.686201  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=6.157687
I20260812 06:18:52.716125  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.030s	user 0.016s	sys 0.012s Metrics: {"bytes_written":7548689,"delete_count":0,"lbm_write_time_us":7687,"lbm_writes_lt_1ms":187,"reinsert_count":0,"update_count":920}
I20260812 06:18:52.716755  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling LogGCOp(51db9c2438f647989d4e08c91c751e1f): free 12017952 bytes of WAL
I20260812 06:18:52.717000  3649 log_reader.cc:385] T 51db9c2438f647989d4e08c91c751e1f: removed 1 log segments from log reader
I20260812 06:18:52.717067  3649 log.cc:1079] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: Deleting log segment in path: /tmp/dist-test-tasksvy_Vr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522304038-3328-0/minicluster-data/ts-0-root/wals/51db9c2438f647989d4e08c91c751e1f/wal-000000038 (ops 186-190)
I20260812 06:18:52.719646  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: LogGCOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:52.720031  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f): perf score=1.000000
I20260812 06:18:52.947801  3328 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.955s	user 1.838s	sys 0.179s
I20260812 06:18:52.952257  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: MajorDeltaCompactionOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.232s	user 0.138s	sys 0.081s Metrics: {"cfile_cache_miss":717,"cfile_cache_miss_bytes":32364239,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2463,"lbm_read_time_us":14446,"lbm_reads_lt_1ms":753,"lbm_write_time_us":37978,"lbm_writes_lt_1ms":727,"mutex_wait_us":1909,"peak_mem_usage":85231716,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":84,"threads_started":1,"update_count":3420}
I20260812 06:18:52.953006  3721 maintenance_manager.cc:419] P 6b11e023fe934754bce058110230bd6c: Scheduling FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f): perf score=19.056125
I20260812 06:18:52.977550  3328 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.029s	user 0.001s	sys 0.000s
I20260812 06:18:52.978148  3328 tablet_server.cc:179] TabletServer@127.3.64.1:0 shutting down...
I20260812 06:18:53.027910  3649 maintenance_manager.cc:643] P 6b11e023fe934754bce058110230bd6c: FlushDeltaMemStoresOp(51db9c2438f647989d4e08c91c751e1f) complete. Timing: real 0.075s	user 0.052s	sys 0.020s Metrics: {"bytes_written":21168707,"delete_count":0,"lbm_write_time_us":29726,"lbm_writes_lt_1ms":519,"reinsert_count":0,"update_count":2580}
I20260812 06:18:53.028693  3328 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:53.028956  3328 tablet_replica.cc:333] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c: stopping tablet replica
I20260812 06:18:53.029145  3328 raft_consensus.cc:2243] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:53.029348  3328 raft_consensus.cc:2272] T 51db9c2438f647989d4e08c91c751e1f P 6b11e023fe934754bce058110230bd6c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:53.032946  3328 tablet_server.cc:196] TabletServer@127.3.64.1:0 shutdown complete.
I20260812 06:18:53.036135  3328 master.cc:562] Master@127.3.64.62:42963 shutting down...
I20260812 06:18:53.039992  3328 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:53.040176  3328 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:53.040233  3328 tablet_replica.cc:333] T 00000000000000000000000000000000 P 103ed782bb88477a8c639f3678fa1dc4: stopping tablet replica
I20260812 06:18:53.052894  3328 master.cc:584] Master@127.3.64.62:42963 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5400 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10830 ms total)

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