[==========] 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:59.822408 29478 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.201.190:40605
I20260812 06:18:59.823468 29478 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:59.824050 29478 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.830093 29485 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:59.830116 29484 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:59.830353 29478 server_base.cc:1061] running on GCE node
W20260812 06:18:59.830361 29488 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:59.830940 29478 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.831049 29478 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:59.831097 29478 hybrid_clock.cc:648] HybridClock initialized: now 1786515539831094 us; error 0 us; skew 500 ppm
I20260812 06:18:59.832918 29478 webserver.cc:533] Webserver started at http://127.28.201.190:44799/ using document root <none> and password file <none>
I20260812 06:18:59.833469 29478 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.833552 29478 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.833843 29478 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.835579 29478 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/master-0-root/instance:
uuid: "694d266c5b144801a3c20cdbd76b9a03"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-07c2"
I20260812 06:18:59.838963 29478 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:59.841046 29493 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:59.841991 29478 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:59.842119 29478 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/master-0-root
uuid: "694d266c5b144801a3c20cdbd76b9a03"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-07c2"
I20260812 06:18:59.842226 29478 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-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:59.858845 29478 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.859575 29478 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:59.859763 29478 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.867810 29478 rpc_server.cc:307] RPC server started. Bound to: 127.28.201.190:40605
I20260812 06:18:59.867835 29555 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.201.190:40605 every 8 connection(s)
I20260812 06:18:59.870054 29556 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:59.876535 29556 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: Bootstrap starting.
I20260812 06:18:59.878955 29556 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.880098 29556 log.cc:826] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:59.882622 29556 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: No bootstrap required, opened a new log
I20260812 06:18:59.885608 29556 raft_consensus.cc:359] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER }
I20260812 06:18:59.885782 29556 raft_consensus.cc:385] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.885838 29556 raft_consensus.cc:740] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 694d266c5b144801a3c20cdbd76b9a03, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.886360 29556 consensus_queue.cc:260] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [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: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER }
I20260812 06:18:59.886492 29556 raft_consensus.cc:399] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.886538 29556 raft_consensus.cc:493] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.886623 29556 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.887430 29556 raft_consensus.cc:515] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER }
I20260812 06:18:59.887821 29556 leader_election.cc:304] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [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: 694d266c5b144801a3c20cdbd76b9a03; no voters: 
I20260812 06:18:59.888078 29556 leader_election.cc:290] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.888252 29559 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.888526 29559 raft_consensus.cc:697] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 1 LEADER]: Becoming Leader. State: Replica: 694d266c5b144801a3c20cdbd76b9a03, State: Running, Role: LEADER
I20260812 06:18:59.888902 29559 consensus_queue.cc:237] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [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: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER }
I20260812 06:18:59.889114 29556 sys_catalog.cc:565] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:59.890661 29560 sys_catalog.cc:455] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "694d266c5b144801a3c20cdbd76b9a03" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER } }
I20260812 06:18:59.890799 29560 sys_catalog.cc:458] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.891131 29561 sys_catalog.cc:455] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 694d266c5b144801a3c20cdbd76b9a03. Latest consensus state: current_term: 1 leader_uuid: "694d266c5b144801a3c20cdbd76b9a03" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "694d266c5b144801a3c20cdbd76b9a03" member_type: VOTER } }
I20260812 06:18:59.891214 29561 sys_catalog.cc:458] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.891531 29478 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:59.893491 29576 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:59.893553 29576 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:59.893635 29571 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:59.894356 29571 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:59.898968 29571 catalog_manager.cc:1383] Generated new cluster ID: b0b6d163b7a14515a35ef291f1273350
I20260812 06:18:59.899030 29571 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:59.909813 29571 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:59.910892 29571 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:59.921130 29571 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: Generated new TSK 0
I20260812 06:18:59.921778 29571 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:59.924363 29478 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.927340 29583 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:59.927416 29580 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:59.927424 29585 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:59.927984 29478 server_base.cc:1061] running on GCE node
I20260812 06:18:59.928154 29478 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.928212 29478 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:59.928236 29478 hybrid_clock.cc:648] HybridClock initialized: now 1786515539928235 us; error 0 us; skew 500 ppm
I20260812 06:18:59.929190 29478 webserver.cc:533] Webserver started at http://127.28.201.129:44783/ using document root <none> and password file <none>
I20260812 06:18:59.929355 29478 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.929411 29478 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.929477 29478 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.929898 29478 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/instance:
uuid: "a1a627107eeb4334aa6fe5d57dfb4391"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-07c2"
I20260812 06:18:59.931720 29478 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:59.932837 29590 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:59.933130 29478 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:59.933207 29478 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root
uuid: "a1a627107eeb4334aa6fe5d57dfb4391"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-07c2"
I20260812 06:18:59.933300 29478 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-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:59.951499 29478 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.952005 29478 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.952512 29478 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:59.953346 29478 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:59.953421 29478 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.953498 29478 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:59.953545 29478 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.960042 29478 rpc_server.cc:307] RPC server started. Bound to: 127.28.201.129:45121
I20260812 06:18:59.960107 29669 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.201.129:45121 every 8 connection(s)
I20260812 06:18:59.975883 29670 heartbeater.cc:344] Connected to a master server at 127.28.201.190:40605
I20260812 06:18:59.976167 29670 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:59.976686 29670 heartbeater.cc:507] Master 127.28.201.190:40605 requested a full tablet report, sending...
I20260812 06:18:59.978228 29510 ts_manager.cc:194] Registered new tserver with Master: a1a627107eeb4334aa6fe5d57dfb4391 (127.28.201.129:45121)
I20260812 06:18:59.978585 29478 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017883444s
I20260812 06:18:59.979815 29510 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44992
I20260812 06:18:59.988332 29510 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44996:
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:19:00.003521 29626 tablet_service.cc:1511] Processing CreateTablet for tablet 0becba9b1074497a8acb983029bef404 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f730484a8ca84ef6bb6a9a59ca9ad9cd]), partition=
I20260812 06:19:00.004001 29626 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0becba9b1074497a8acb983029bef404. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:00.006234 29686 tablet_bootstrap.cc:492] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Bootstrap starting.
I20260812 06:19:00.007622 29686 tablet_bootstrap.cc:654] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:00.008888 29686 tablet_bootstrap.cc:492] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: No bootstrap required, opened a new log
I20260812 06:19:00.009023 29686 ts_tablet_manager.cc:1403] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:00.009423 29686 raft_consensus.cc:359] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1a627107eeb4334aa6fe5d57dfb4391" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 45121 } }
I20260812 06:19:00.009552 29686 raft_consensus.cc:385] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:00.009621 29686 raft_consensus.cc:740] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a1a627107eeb4334aa6fe5d57dfb4391, State: Initialized, Role: FOLLOWER
I20260812 06:19:00.009799 29686 consensus_queue.cc:260] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [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: "a1a627107eeb4334aa6fe5d57dfb4391" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 45121 } }
I20260812 06:19:00.009907 29686 raft_consensus.cc:399] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:00.009956 29686 raft_consensus.cc:493] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:00.010012 29686 raft_consensus.cc:3060] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:00.011196 29686 raft_consensus.cc:515] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1a627107eeb4334aa6fe5d57dfb4391" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 45121 } }
I20260812 06:19:00.011386 29686 leader_election.cc:304] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [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: a1a627107eeb4334aa6fe5d57dfb4391; no voters: 
I20260812 06:19:00.011646 29686 leader_election.cc:290] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:00.011749 29689 raft_consensus.cc:2804] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:00.011934 29689 raft_consensus.cc:697] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 1 LEADER]: Becoming Leader. State: Replica: a1a627107eeb4334aa6fe5d57dfb4391, State: Running, Role: LEADER
I20260812 06:19:00.012049 29686 ts_tablet_manager.cc:1434] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:00.012130 29689 consensus_queue.cc:237] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [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: "a1a627107eeb4334aa6fe5d57dfb4391" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 45121 } }
I20260812 06:19:00.012392 29670 heartbeater.cc:499] Master 127.28.201.190:40605 was elected leader, sending a full tablet report...
I20260812 06:19:00.015460 29510 catalog_manager.cc:5719] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 reported cstate change: term changed from 0 to 1, leader changed from <none> to a1a627107eeb4334aa6fe5d57dfb4391 (127.28.201.129). New cstate: current_term: 1 leader_uuid: "a1a627107eeb4334aa6fe5d57dfb4391" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1a627107eeb4334aa6fe5d57dfb4391" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 45121 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:00.082258 29478 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.021s	sys 0.006s
I20260812 06:19:00.211336 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushMRSOp(0becba9b1074497a8acb983029bef404): perf score=15.086190
I20260812 06:19:00.375478 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushMRSOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.164s	user 0.119s	sys 0.044s Metrics: {"bytes_written":13579237,"cfile_init":1,"compiler_manager_pool.queue_time_us":184,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":888,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41630,"lbm_writes_lt_1ms":698,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":123,"threads_started":1,"update_count":1655}
I20260812 06:19:00.376685 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling LogGCOp(0becba9b1074497a8acb983029bef404): free 20743880 bytes of WAL
I20260812 06:19:00.376976 29596 log_reader.cc:385] T 0becba9b1074497a8acb983029bef404: removed 2 log segments from log reader
I20260812 06:19:00.377043 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000001 (ops 1-6)
I20260812 06:19:00.377094 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000002 (ops 7-11)
I20260812 06:19:00.382557 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: LogGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:00.382890 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=3.181125
I20260812 06:19:00.397764 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:00.398185 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404): 12719217 bytes on disk
I20260812 06:19:00.398743 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.399132 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:00.406724 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":2573,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:19:00.407135 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:00.581182 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.174s	user 0.107s	sys 0.063s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364518,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":588,"lbm_read_time_us":10458,"lbm_reads_lt_1ms":559,"lbm_write_time_us":32204,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":310,"threads_started":5,"update_count":2450}
I20260812 06:19:00.581848 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=10.126437
I20260812 06:19:00.630007 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.048s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18704,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.630498 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:00.652966 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.653414 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:00.667692 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.014s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.668176 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:00.826201 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.158s	user 0.118s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":193,"lbm_read_time_us":10882,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31002,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:19:00.826822 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:00.878132 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.051s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22313,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.878566 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:00.889196 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.889858 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:01.048142 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.158s	user 0.122s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":10040,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31059,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:19:01.048700 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:01.101465 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.053s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.102047 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:01.113601 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.114114 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:01.272488 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.158s	user 0.114s	sys 0.036s 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":377,"lbm_read_time_us":9608,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31873,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:01.273135 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:01.322221 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.049s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19655,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.322872 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:01.334254 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.334864 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:01.516057 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.181s	user 0.121s	sys 0.051s 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":273,"lbm_read_time_us":10937,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34869,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:01.516793 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:01.567150 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.050s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20962,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.567770 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushMRSOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:01.611547 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushMRSOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.044s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1775,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:01.612824 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling LogGCOp(0becba9b1074497a8acb983029bef404): free 112239270 bytes of WAL
I20260812 06:19:01.613153 29596 log_reader.cc:385] T 0becba9b1074497a8acb983029bef404: removed 11 log segments from log reader
I20260812 06:19:01.613219 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000003 (ops 12-16)
I20260812 06:19:01.613270 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000004 (ops 17-20)
I20260812 06:19:01.613320 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000005 (ops 21-25)
I20260812 06:19:01.613380 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000006 (ops 26-30)
I20260812 06:19:01.613420 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000007 (ops 31-35)
I20260812 06:19:01.613446 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000008 (ops 36-40)
I20260812 06:19:01.613482 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000009 (ops 41-45)
I20260812 06:19:01.613512 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000010 (ops 46-50)
I20260812 06:19:01.613543 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000011 (ops 51-55)
I20260812 06:19:01.613579 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000012 (ops 56-60)
I20260812 06:19:01.613615 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000013 (ops 61-65)
I20260812 06:19:01.641407 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: LogGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:01.641815 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404): 462 bytes on disk
I20260812 06:19:01.642234 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:01.642690 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=6.157687
I20260812 06:19:01.663793 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.021s	user 0.013s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9170,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:01.664288 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:01.860572 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.196s	user 0.122s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":14235,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32978,"lbm_writes_lt_1ms":643,"mutex_wait_us":346,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:19:01.861356 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=16.079562
I20260812 06:19:01.923024 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.061s	user 0.044s	sys 0.013s Metrics: {"bytes_written":18009849,"delete_count":0,"lbm_write_time_us":27009,"lbm_writes_lt_1ms":442,"reinsert_count":0,"update_count":2195}
I20260812 06:19:01.923754 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=1.196750
I20260812 06:19:01.943879 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.020s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:19:01.944375 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:01.959240 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.959774 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:02.162823 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.203s	user 0.138s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877187,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1357,"lbm_read_time_us":14789,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34579,"lbm_writes_lt_1ms":643,"mutex_wait_us":841,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:19:02.163457 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:02.229285 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.066s	user 0.024s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26214,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.229776 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:02.240527 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.241044 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:02.426597 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.185s	user 0.133s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":11610,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31982,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:02.427240 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:02.478832 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.051s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21794,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.479512 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:02.497133 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.497771 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:02.664105 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.166s	user 0.096s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":11976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29789,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.664779 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:02.723850 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.059s	user 0.022s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22492,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.724413 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:02.735245 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.735800 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:02.909590 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.174s	user 0.126s	sys 0.042s 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":805,"lbm_read_time_us":11840,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29410,"lbm_writes_lt_1ms":543,"mutex_wait_us":243,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.910300 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:02.970726 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.060s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22093,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.971380 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:02.989370 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.989907 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:03.161234 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.171s	user 0.116s	sys 0.047s 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":96,"lbm_read_time_us":11918,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27413,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:03.161906 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=11.118625
I20260812 06:19:03.199788 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.038s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14472,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:03.200650 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:03.224278 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.023s	user 0.013s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5667,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:03.224735 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:03.235423 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.235864 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushMRSOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:03.272984 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushMRSOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.037s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1710,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:03.273734 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling LogGCOp(0becba9b1074497a8acb983029bef404): free 140885454 bytes of WAL
I20260812 06:19:03.273972 29596 log_reader.cc:385] T 0becba9b1074497a8acb983029bef404: removed 14 log segments from log reader
I20260812 06:19:03.274019 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000014 (ops 66-70)
I20260812 06:19:03.274046 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000015 (ops 71-74)
I20260812 06:19:03.274111 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000016 (ops 75-79)
I20260812 06:19:03.274151 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000017 (ops 80-84)
I20260812 06:19:03.274199 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000018 (ops 85-89)
I20260812 06:19:03.274258 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000019 (ops 90-94)
I20260812 06:19:03.274331 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000020 (ops 95-99)
I20260812 06:19:03.274374 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000021 (ops 100-104)
I20260812 06:19:03.274423 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000022 (ops 105-109)
I20260812 06:19:03.274463 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000023 (ops 110-114)
I20260812 06:19:03.274503 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000024 (ops 115-118)
I20260812 06:19:03.274542 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000025 (ops 119-123)
I20260812 06:19:03.274581 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000026 (ops 124-128)
I20260812 06:19:03.274621 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000027 (ops 129-132)
I20260812 06:19:03.303613 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: LogGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:03.304083 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404): 493 bytes on disk
I20260812 06:19:03.304539 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:03.305138 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=3.181125
I20260812 06:19:03.318130 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.013s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4488,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:03.318557 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:03.328289 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:03.328732 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:03.559257 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.230s	user 0.150s	sys 0.072s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979848,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":167,"lbm_read_time_us":14117,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38196,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:03.559890 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=18.063937
I20260812 06:19:03.617060 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.056s	user 0.029s	sys 0.026s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25680,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:03.617686 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:03.788589 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.171s	user 0.138s	sys 0.032s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":217,"lbm_read_time_us":12352,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27969,"lbm_writes_lt_1ms":543,"mutex_wait_us":531,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:03.789283 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:03.848461 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.059s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.849011 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:03.868598 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.019s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.869093 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:04.035403 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.166s	user 0.111s	sys 0.054s 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":688,"lbm_read_time_us":12437,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27076,"lbm_writes_lt_1ms":543,"mutex_wait_us":355,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:04.035955 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:04.089635 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.054s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24393,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.095914 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.121912 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.122430 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.132519 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.133057 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:04.326406 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.193s	user 0.142s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":136,"lbm_read_time_us":13948,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34643,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:04.327028 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:04.387692 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.060s	user 0.033s	sys 0.026s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21989,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.388468 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.405113 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.405794 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:04.570096 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.164s	user 0.132s	sys 0.032s 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":1444,"lbm_read_time_us":9884,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29440,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:04.570847 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:04.627590 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.057s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20519,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.628100 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.638947 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.639489 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushMRSOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:04.680173 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushMRSOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.041s	user 0.023s	sys 0.006s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1303,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1535,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:04.680938 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling LogGCOp(0becba9b1074497a8acb983029bef404): free 108535684 bytes of WAL
I20260812 06:19:04.681169 29596 log_reader.cc:385] T 0becba9b1074497a8acb983029bef404: removed 11 log segments from log reader
I20260812 06:19:04.681216 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000028 (ops 133-137)
I20260812 06:19:04.681244 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000029 (ops 138-142)
I20260812 06:19:04.681310 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000030 (ops 143-147)
I20260812 06:19:04.681351 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000031 (ops 148-152)
I20260812 06:19:04.681393 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000032 (ops 153-156)
I20260812 06:19:04.681461 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000033 (ops 157-161)
I20260812 06:19:04.681495 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000034 (ops 162-166)
I20260812 06:19:04.681530 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000035 (ops 167-170)
I20260812 06:19:04.681594 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000036 (ops 171-175)
I20260812 06:19:04.681635 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000037 (ops 176-180)
I20260812 06:19:04.681675 29596 log.cc:1079] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0becba9b1074497a8acb983029bef404/wal-000000038 (ops 181-185)
I20260812 06:19:04.705350 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: LogGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:04.705889 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404): 446 bytes on disk
I20260812 06:19:04.706542 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: UndoDeltaBlockGCOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:19:04.707554 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.730599 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.023s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.731125 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:04.741413 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.741940 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:04.967954 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.226s	user 0.156s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1855,"lbm_read_time_us":15728,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40280,"lbm_writes_lt_1ms":743,"mutex_wait_us":1463,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":29952,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:04.968631 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=14.095187
I20260812 06:19:05.024887 29478 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.943s	user 1.750s	sys 0.201s
I20260812 06:19:05.028281 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.059s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.028869 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404): perf score=2.188937
I20260812 06:19:05.039113 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: FlushDeltaMemStoresOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.039525 29671 maintenance_manager.cc:419] P a1a627107eeb4334aa6fe5d57dfb4391: Scheduling MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404): perf score=1.000000
I20260812 06:19:05.089138 29478 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.001s	sys 0.000s
I20260812 06:19:05.089797 29478 tablet_server.cc:179] TabletServer@127.28.201.129:0 shutting down...
I20260812 06:19:05.168485 29596 maintenance_manager.cc:643] P a1a627107eeb4334aa6fe5d57dfb4391: MajorDeltaCompactionOp(0becba9b1074497a8acb983029bef404) complete. Timing: real 0.129s	user 0.080s	sys 0.048s Metrics: {"cfile_cache_hit":250,"cfile_cache_hit_bytes":10217107,"cfile_cache_miss":282,"cfile_cache_miss_bytes":14557582,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":922,"lbm_read_time_us":6383,"lbm_reads_lt_1ms":314,"lbm_write_time_us":25237,"lbm_writes_lt_1ms":543,"mutex_wait_us":195,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:05.169246 29478 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:05.169669 29478 tablet_replica.cc:333] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391: stopping tablet replica
I20260812 06:19:05.169900 29478 raft_consensus.cc:2243] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:05.170173 29478 raft_consensus.cc:2272] T 0becba9b1074497a8acb983029bef404 P a1a627107eeb4334aa6fe5d57dfb4391 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:05.185163 29478 tablet_server.cc:196] TabletServer@127.28.201.129:0 shutdown complete.
I20260812 06:19:05.214540 29478 master.cc:562] Master@127.28.201.190:40605 shutting down...
I20260812 06:19:05.218257 29478 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:05.218421 29478 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:05.218477 29478 tablet_replica.cc:333] T 00000000000000000000000000000000 P 694d266c5b144801a3c20cdbd76b9a03: stopping tablet replica
I20260812 06:19:05.231009 29478 master.cc:584] Master@127.28.201.190:40605 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5496 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:05.331926 29478 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.201.190:34015
I20260812 06:19:05.332335 29478 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:05.334678 29478 server_base.cc:1061] running on GCE node
W20260812 06:19:05.334723 29713 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:19:05.334718 29715 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:19:05.334777 29712 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:19:05.335171 29478 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.335239 29478 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:19:05.335266 29478 hybrid_clock.cc:648] HybridClock initialized: now 1786515545335266 us; error 0 us; skew 500 ppm
I20260812 06:19:05.336131 29478 webserver.cc:533] Webserver started at http://127.28.201.190:45359/ using document root <none> and password file <none>
I20260812 06:19:05.336313 29478 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.336387 29478 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.336478 29478 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.336915 29478 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/master-0-root/instance:
uuid: "5320d8f669c64f1ebfa144782d167a4f"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-07c2"
I20260812 06:19:05.338965 29478 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:05.340590 29721 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:19:05.340883 29478 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.340991 29478 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/master-0-root
uuid: "5320d8f669c64f1ebfa144782d167a4f"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-07c2"
I20260812 06:19:05.341071 29478 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-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:19:05.353256 29478 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.353647 29478 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.358127 29478 rpc_server.cc:307] RPC server started. Bound to: 127.28.201.190:34015
I20260812 06:19:05.360101 29781 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.201.190:34015 every 8 connection(s)
I20260812 06:19:05.360599 29783 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:19:05.362414 29783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f: Bootstrap starting.
I20260812 06:19:05.363240 29783 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.364527 29783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f: No bootstrap required, opened a new log
I20260812 06:19:05.364951 29783 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER }
I20260812 06:19:05.365038 29783 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.365100 29783 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5320d8f669c64f1ebfa144782d167a4f, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.365288 29783 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [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: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER }
I20260812 06:19:05.365360 29783 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.365430 29783 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.365490 29783 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.366166 29783 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER }
I20260812 06:19:05.366315 29783 leader_election.cc:304] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [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: 5320d8f669c64f1ebfa144782d167a4f; no voters: 
I20260812 06:19:05.366528 29783 leader_election.cc:290] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.366640 29787 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.366869 29787 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 1 LEADER]: Becoming Leader. State: Replica: 5320d8f669c64f1ebfa144782d167a4f, State: Running, Role: LEADER
I20260812 06:19:05.367000 29783 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:05.367035 29787 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [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: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER }
I20260812 06:19:05.367522 29789 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5320d8f669c64f1ebfa144782d167a4f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER } }
I20260812 06:19:05.367633 29789 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.367537 29790 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5320d8f669c64f1ebfa144782d167a4f. Latest consensus state: current_term: 1 leader_uuid: "5320d8f669c64f1ebfa144782d167a4f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5320d8f669c64f1ebfa144782d167a4f" member_type: VOTER } }
I20260812 06:19:05.367771 29790 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.368495 29795 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:05.369246 29795 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:05.369428 29478 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:05.370929 29795 catalog_manager.cc:1383] Generated new cluster ID: bec87ad28728402f87cfefdb26963766
I20260812 06:19:05.370976 29795 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.377494 29795 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.377986 29795 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.387627 29795 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f: Generated new TSK 0
I20260812 06:19:05.387796 29795 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.401721 29478 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.403644 29814 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:19:05.403662 29810 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:19:05.403822 29478 server_base.cc:1061] running on GCE node
W20260812 06:19:05.403682 29812 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:19:05.404138 29478 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.404191 29478 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:19:05.404207 29478 hybrid_clock.cc:648] HybridClock initialized: now 1786515545404207 us; error 0 us; skew 500 ppm
I20260812 06:19:05.404982 29478 webserver.cc:533] Webserver started at http://127.28.201.129:46607/ using document root <none> and password file <none>
I20260812 06:19:05.405149 29478 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.405205 29478 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.405262 29478 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.405613 29478 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/instance:
uuid: "7185d20131fa42b29e4dcc0d54602319"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-07c2"
I20260812 06:19:05.407058 29478 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:05.407986 29821 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:19:05.408224 29478 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.408313 29478 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root
uuid: "7185d20131fa42b29e4dcc0d54602319"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-07c2"
I20260812 06:19:05.408404 29478 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-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:19:05.421391 29478 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.421744 29478 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.422046 29478 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:05.422508 29478 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:05.422569 29478 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.422631 29478 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:05.422664 29478 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.426935 29478 rpc_server.cc:307] RPC server started. Bound to: 127.28.201.129:36405
I20260812 06:19:05.427618 29895 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.201.129:36405 every 8 connection(s)
I20260812 06:19:05.437013 29897 heartbeater.cc:344] Connected to a master server at 127.28.201.190:34015
I20260812 06:19:05.437109 29897 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:05.437366 29897 heartbeater.cc:507] Master 127.28.201.190:34015 requested a full tablet report, sending...
I20260812 06:19:05.438038 29739 ts_manager.cc:194] Registered new tserver with Master: 7185d20131fa42b29e4dcc0d54602319 (127.28.201.129:36405)
I20260812 06:19:05.438810 29478 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01097814s
I20260812 06:19:05.438818 29739 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49392
I20260812 06:19:05.445798 29739 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49394:
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:19:05.454515 29852 tablet_service.cc:1511] Processing CreateTablet for tablet 0cd5fb9d22134751bfcfd4a7359ec119 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a29837ebbaf14b1284c8596b31135431]), partition=
I20260812 06:19:05.454808 29852 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0cd5fb9d22134751bfcfd4a7359ec119. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.456976 29912 tablet_bootstrap.cc:492] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Bootstrap starting.
I20260812 06:19:05.458076 29912 tablet_bootstrap.cc:654] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.459184 29912 tablet_bootstrap.cc:492] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: No bootstrap required, opened a new log
I20260812 06:19:05.459259 29912 ts_tablet_manager.cc:1403] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:05.459790 29912 raft_consensus.cc:359] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7185d20131fa42b29e4dcc0d54602319" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 36405 } }
I20260812 06:19:05.459908 29912 raft_consensus.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.459985 29912 raft_consensus.cc:740] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7185d20131fa42b29e4dcc0d54602319, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.460325 29912 consensus_queue.cc:260] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [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: "7185d20131fa42b29e4dcc0d54602319" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 36405 } }
I20260812 06:19:05.460459 29912 raft_consensus.cc:399] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.460515 29912 raft_consensus.cc:493] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.460577 29912 raft_consensus.cc:3060] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.461344 29912 raft_consensus.cc:515] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7185d20131fa42b29e4dcc0d54602319" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 36405 } }
I20260812 06:19:05.461495 29912 leader_election.cc:304] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [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: 7185d20131fa42b29e4dcc0d54602319; no voters: 
I20260812 06:19:05.461715 29912 leader_election.cc:290] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.461869 29914 raft_consensus.cc:2804] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.462116 29914 raft_consensus.cc:697] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 1 LEADER]: Becoming Leader. State: Replica: 7185d20131fa42b29e4dcc0d54602319, State: Running, Role: LEADER
I20260812 06:19:05.462121 29912 ts_tablet_manager.cc:1434] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:05.462193 29897 heartbeater.cc:499] Master 127.28.201.190:34015 was elected leader, sending a full tablet report...
I20260812 06:19:05.462277 29914 consensus_queue.cc:237] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [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: "7185d20131fa42b29e4dcc0d54602319" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 36405 } }
I20260812 06:19:05.463620 29739 catalog_manager.cc:5719] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7185d20131fa42b29e4dcc0d54602319 (127.28.201.129). New cstate: current_term: 1 leader_uuid: "7185d20131fa42b29e4dcc0d54602319" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7185d20131fa42b29e4dcc0d54602319" member_type: VOTER last_known_addr { host: "127.28.201.129" port: 36405 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:05.523097 29478 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:19:05.678263 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=19.054940
I20260812 06:19:05.823414 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.145s	user 0.109s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":944,"drs_written":1,"lbm_read_time_us":114,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37011,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:05.824280 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 20743831 bytes of WAL
I20260812 06:19:05.824540 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 2 log segments from log reader
I20260812 06:19:05.824605 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000001 (ops 1-6)
I20260812 06:19:05.824651 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000002 (ops 7-11)
I20260812 06:19:05.830770 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:05.831436 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=3.181125
I20260812 06:19:05.852823 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.021s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:05.853238 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:05.862671 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3552,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.863077 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119): 16411392 bytes on disk
I20260812 06:19:05.863520 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":112,"lbm_reads_lt_1ms":4}
I20260812 06:19:05.863871 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:06.043218 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.179s	user 0.127s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774795,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":485,"lbm_read_time_us":14438,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28645,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":307,"threads_started":5,"update_count":2500}
I20260812 06:19:06.043766 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:06.115221 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.071s	user 0.041s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27842,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.115760 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:06.132898 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.133417 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:06.307761 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.174s	user 0.105s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":597,"lbm_read_time_us":12530,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26376,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:06.308346 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:06.358390 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.050s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21189,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.358857 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:06.370465 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.370965 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:06.547223 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.176s	user 0.115s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":11306,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27903,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:19:06.547861 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:06.600138 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.052s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.600623 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:06.611836 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.612466 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:06.773130 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.160s	user 0.113s	sys 0.040s 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":860,"lbm_read_time_us":10874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29658,"lbm_writes_lt_1ms":543,"mutex_wait_us":227,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:06.773824 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:06.822047 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.048s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.822568 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:06.833961 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.834441 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:06.983443 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.149s	user 0.113s	sys 0.032s 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":211,"lbm_read_time_us":9603,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29992,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:19:06.984161 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=11.118625
I20260812 06:19:07.012732 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.028s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12694,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:07.013353 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:07.025138 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.025808 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:07.059741 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1286,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2376,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:07.060376 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 112239356 bytes of WAL
I20260812 06:19:07.060702 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 11 log segments from log reader
I20260812 06:19:07.060809 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000003 (ops 12-16)
I20260812 06:19:07.060873 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000004 (ops 17-21)
I20260812 06:19:07.060905 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000005 (ops 22-26)
I20260812 06:19:07.060943 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000006 (ops 27-30)
I20260812 06:19:07.060972 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000007 (ops 31-35)
I20260812 06:19:07.061007 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000008 (ops 36-40)
I20260812 06:19:07.061048 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000009 (ops 41-45)
I20260812 06:19:07.061096 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000010 (ops 46-50)
I20260812 06:19:07.061138 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000011 (ops 51-55)
I20260812 06:19:07.061185 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000012 (ops 56-60)
I20260812 06:19:07.061295 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000013 (ops 61-65)
I20260812 06:19:07.088789 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.028s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:19:07.089337 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119): 462 bytes on disk
I20260812 06:19:07.089960 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.090622 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=4.173312
I20260812 06:19:07.105571 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5333392,"delete_count":0,"lbm_write_time_us":6109,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:19:07.106062 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 12017932 bytes of WAL
I20260812 06:19:07.106292 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 1 log segments from log reader
I20260812 06:19:07.106361 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000014 (ops 66-70)
I20260812 06:19:07.108893 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:07.109236 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.196750
I20260812 06:19:07.120076 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3791,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:07.120631 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:07.294667 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.174s	user 0.129s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":328,"lbm_read_time_us":11426,"lbm_reads_lt_1ms":666,"lbm_write_time_us":33021,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":36352,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:07.295464 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:07.343501 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.048s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20744,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.344020 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:07.362008 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.362495 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:07.514813 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.152s	user 0.097s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":11171,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30117,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":71040,"update_count":2500}
I20260812 06:19:07.515513 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:07.564983 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.049s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19932,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.565582 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:07.577983 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4241,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.578531 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:07.722278 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.144s	user 0.115s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":940,"lbm_read_time_us":10340,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29834,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:07.723093 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=10.126437
I20260812 06:19:07.757441 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.034s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.757922 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:07.783775 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.026s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.784246 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:07.794358 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.794778 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:07.949571 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.155s	user 0.119s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":43,"lbm_read_time_us":10420,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32317,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:19:07.950213 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=10.126437
I20260812 06:19:07.995519 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.045s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16479,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.996063 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:08.006510 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.006949 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:08.133144 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.126s	user 0.090s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":8700,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25058,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:19:08.133893 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=10.126437
I20260812 06:19:08.185989 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.052s	user 0.021s	sys 0.025s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.186532 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:08.196830 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.197276 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:08.347934 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.150s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":10708,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24990,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:08.349210 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=10.126437
I20260812 06:19:08.391705 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.042s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16427,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.392215 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:08.403328 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.404034 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:08.435565 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1825,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1598,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:08.436194 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 108535458 bytes of WAL
I20260812 06:19:08.436419 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 11 log segments from log reader
I20260812 06:19:08.436465 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000015 (ops 71-75)
I20260812 06:19:08.436491 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000016 (ops 76-80)
I20260812 06:19:08.436560 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000017 (ops 81-84)
I20260812 06:19:08.436621 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000018 (ops 85-89)
I20260812 06:19:08.436661 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000019 (ops 90-94)
I20260812 06:19:08.436695 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000020 (ops 95-99)
I20260812 06:19:08.436735 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000021 (ops 100-104)
I20260812 06:19:08.436774 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000022 (ops 105-108)
I20260812 06:19:08.436810 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000023 (ops 109-113)
I20260812 06:19:08.436847 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000024 (ops 114-118)
I20260812 06:19:08.436887 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000025 (ops 119-123)
I20260812 06:19:08.461567 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:08.461998 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=4.173312
I20260812 06:19:08.486202 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.024s	user 0.006s	sys 0.015s Metrics: {"bytes_written":5743634,"delete_count":0,"lbm_write_time_us":6437,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:19:08.486760 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 12017932 bytes of WAL
I20260812 06:19:08.486987 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 1 log segments from log reader
I20260812 06:19:08.487031 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000026 (ops 124-128)
I20260812 06:19:08.489372 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:08.489729 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.196750
I20260812 06:19:08.497144 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2330,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:19:08.497581 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119): 462 bytes on disk
I20260812 06:19:08.498129 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.498730 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:08.695403 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.196s	user 0.132s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1564,"lbm_read_time_us":14250,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33701,"lbm_writes_lt_1ms":643,"mutex_wait_us":562,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":108,"threads_started":1,"update_count":3000}
I20260812 06:19:08.696273 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:08.763926 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.067s	user 0.020s	sys 0.046s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28284,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.764655 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:08.785416 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.785887 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:08.797540 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.798094 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.013790 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.215s	user 0.124s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1154,"lbm_read_time_us":15182,"lbm_reads_lt_1ms":673,"lbm_write_time_us":41500,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:19:09.014477 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:09.070344 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.056s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.071115 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.224835 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.153s	user 0.093s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":648,"lbm_read_time_us":9227,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24680,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:19:09.227782 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=10.126437
I20260812 06:19:09.265430 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.037s	user 0.027s	sys 0.006s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14945,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.266193 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.440279 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.174s	user 0.157s	sys 0.015s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":208,"lbm_read_time_us":10801,"lbm_reads_lt_1ms":363,"lbm_write_time_us":26270,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.441125 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=15.087375
I20260812 06:19:09.488859 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21290,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:09.489405 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:09.503192 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5096,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.503724 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.665004 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.161s	user 0.133s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":10629,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32789,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:19:09.665714 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:09.716467 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.051s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20650,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.716991 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:09.729000 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.729588 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.892913 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.163s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":9018,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30655,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:19:09.893698 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=14.095187
I20260812 06:19:09.944999 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.051s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.945700 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:09.984668 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushMRSOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.039s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1513,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1499,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:09.985544 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119): 471 bytes on disk
I20260812 06:19:09.986135 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: UndoDeltaBlockGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.986711 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=3.181125
I20260812 06:19:10.000385 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:10.000946 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119): free 117302834 bytes of WAL
I20260812 06:19:10.001214 29826 log_reader.cc:385] T 0cd5fb9d22134751bfcfd4a7359ec119: removed 12 log segments from log reader
I20260812 06:19:10.001274 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000027 (ops 129-133)
I20260812 06:19:10.001315 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000028 (ops 134-138)
I20260812 06:19:10.001349 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000029 (ops 139-142)
I20260812 06:19:10.001372 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000030 (ops 143-147)
I20260812 06:19:10.001398 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000031 (ops 148-152)
I20260812 06:19:10.001426 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000032 (ops 153-157)
I20260812 06:19:10.001459 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000033 (ops 158-162)
I20260812 06:19:10.001494 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000034 (ops 163-167)
I20260812 06:19:10.001521 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000035 (ops 168-172)
I20260812 06:19:10.001546 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000036 (ops 173-176)
I20260812 06:19:10.001575 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000037 (ops 177-181)
I20260812 06:19:10.001605 29826 log.cc:1079] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: Deleting log segment in path: /tmp/dist-test-taskqwjomG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539812065-29478-0/minicluster-data/ts-0-root/wals/0cd5fb9d22134751bfcfd4a7359ec119/wal-000000038 (ops 182-186)
I20260812 06:19:10.027623 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: LogGCOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:10.028115 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:10.054158 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.026s	user 0.001s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4782,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.054641 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:10.065568 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.066146 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=1.000000
I20260812 06:19:10.295826 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: MajorDeltaCompactionOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.229s	user 0.145s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":536,"lbm_read_time_us":14843,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41282,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28032,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:10.296516 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=18.063937
I20260812 06:19:10.345520 29478 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.822s	user 1.782s	sys 0.154s
I20260812 06:19:10.365366 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.069s	user 0.038s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28610,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:10.365859 29898 maintenance_manager.cc:419] P 7185d20131fa42b29e4dcc0d54602319: Scheduling FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119): perf score=2.188937
I20260812 06:19:10.370631 29478 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.025s	user 0.001s	sys 0.000s
I20260812 06:19:10.371100 29478 tablet_server.cc:179] TabletServer@127.28.201.129:0 shutting down...
I20260812 06:19:10.380627 29826 maintenance_manager.cc:643] P 7185d20131fa42b29e4dcc0d54602319: FlushDeltaMemStoresOp(0cd5fb9d22134751bfcfd4a7359ec119) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.381152 29478 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:10.381364 29478 tablet_replica.cc:333] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319: stopping tablet replica
I20260812 06:19:10.381568 29478 raft_consensus.cc:2243] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.381704 29478 raft_consensus.cc:2272] T 0cd5fb9d22134751bfcfd4a7359ec119 P 7185d20131fa42b29e4dcc0d54602319 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.395130 29478 tablet_server.cc:196] TabletServer@127.28.201.129:0 shutdown complete.
I20260812 06:19:10.398052 29478 master.cc:562] Master@127.28.201.190:34015 shutting down...
I20260812 06:19:10.401437 29478 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.401575 29478 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.401623 29478 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5320d8f669c64f1ebfa144782d167a4f: stopping tablet replica
I20260812 06:19:10.415254 29478 master.cc:584] Master@127.28.201.190:34015 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5184 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10681 ms total)

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