[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:26.047596 28391 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.185.254:36977
I20260812 06:20:26.048628 28391 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:26.049315 28391 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:26.056128 28391 server_base.cc:1061] running on GCE node
W20260812 06:20:26.056080 28399 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.056073 28398 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.056337 28403 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.056885 28391 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.057044 28391 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.057085 28391 hybrid_clock.cc:648] HybridClock initialized: now 1786515626057083 us; error 0 us; skew 500 ppm
I20260812 06:20:26.058892 28391 webserver.cc:533] Webserver started at http://127.27.185.254:34351/ using document root <none> and password file <none>
I20260812 06:20:26.059413 28391 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.059474 28391 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.059679 28391 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.061494 28391 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/master-0-root/instance:
uuid: "423eb757c8ea4c69a1f36dcc6fbf1267"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-ffrd"
I20260812 06:20:26.065249 28391 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:20:26.067330 28409 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.068493 28391 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.068658 28391 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/master-0-root
uuid: "423eb757c8ea4c69a1f36dcc6fbf1267"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-ffrd"
I20260812 06:20:26.068805 28391 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.088232 28391 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.088872 28391 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:26.089112 28391 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.096613 28391 rpc_server.cc:307] RPC server started. Bound to: 127.27.185.254:36977
I20260812 06:20:26.096669 28488 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.185.254:36977 every 8 connection(s)
I20260812 06:20:26.099167 28492 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.104753 28492 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: Bootstrap starting.
I20260812 06:20:26.107177 28492 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.108134 28492 log.cc:826] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:26.109884 28492 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: No bootstrap required, opened a new log
I20260812 06:20:26.112732 28492 raft_consensus.cc:359] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER }
I20260812 06:20:26.113010 28492 raft_consensus.cc:385] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.113114 28492 raft_consensus.cc:740] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 423eb757c8ea4c69a1f36dcc6fbf1267, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.113726 28492 consensus_queue.cc:260] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [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: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER }
I20260812 06:20:26.113920 28492 raft_consensus.cc:399] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.114001 28492 raft_consensus.cc:493] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.114146 28492 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.114959 28492 raft_consensus.cc:515] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER }
I20260812 06:20:26.115404 28492 leader_election.cc:304] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [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: 423eb757c8ea4c69a1f36dcc6fbf1267; no voters: 
I20260812 06:20:26.115849 28492 leader_election.cc:290] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.116107 28499 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.116392 28499 raft_consensus.cc:697] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 1 LEADER]: Becoming Leader. State: Replica: 423eb757c8ea4c69a1f36dcc6fbf1267, State: Running, Role: LEADER
I20260812 06:20:26.116748 28499 consensus_queue.cc:237] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [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: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER }
I20260812 06:20:26.116990 28492 sys_catalog.cc:565] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.118749 28503 sys_catalog.cc:455] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 423eb757c8ea4c69a1f36dcc6fbf1267. Latest consensus state: current_term: 1 leader_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER } }
I20260812 06:20:26.118746 28502 sys_catalog.cc:455] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "423eb757c8ea4c69a1f36dcc6fbf1267" member_type: VOTER } }
I20260812 06:20:26.118924 28503 sys_catalog.cc:458] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.118939 28502 sys_catalog.cc:458] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.119385 28391 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.119513 28528 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.121737 28528 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.126354 28528 catalog_manager.cc:1383] Generated new cluster ID: 37b4a63e1c0d49e2aa0cec5581a7d66a
I20260812 06:20:26.126439 28528 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:26.164415 28528 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:26.165493 28528 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:26.186995 28528 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: Generated new TSK 0
I20260812 06:20:26.187734 28528 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:26.248328 28391 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.251173 28546 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.251462 28391 server_base.cc:1061] running on GCE node
W20260812 06:20:26.251142 28553 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.251153 28548 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.251773 28391 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.251818 28391 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.251834 28391 hybrid_clock.cc:648] HybridClock initialized: now 1786515626251835 us; error 0 us; skew 500 ppm
I20260812 06:20:26.252756 28391 webserver.cc:533] Webserver started at http://127.27.185.193:40765/ using document root <none> and password file <none>
I20260812 06:20:26.252974 28391 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.253037 28391 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.253111 28391 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.253504 28391 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/instance:
uuid: "36c5b9dd084c447185c1b17cc111a2c8"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-ffrd"
I20260812 06:20:26.254988 28391 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.255963 28566 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.256201 28391 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.256268 28391 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root
uuid: "36c5b9dd084c447185c1b17cc111a2c8"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-ffrd"
I20260812 06:20:26.256350 28391 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.288661 28391 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.289208 28391 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.289702 28391 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:26.290529 28391 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:26.290581 28391 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.290653 28391 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:26.290699 28391 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.295429 28391 rpc_server.cc:307] RPC server started. Bound to: 127.27.185.193:33511
I20260812 06:20:26.295897 28668 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.185.193:33511 every 8 connection(s)
I20260812 06:20:26.304004 28669 heartbeater.cc:344] Connected to a master server at 127.27.185.254:36977
I20260812 06:20:26.304239 28669 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:26.304593 28669 heartbeater.cc:507] Master 127.27.185.254:36977 requested a full tablet report, sending...
I20260812 06:20:26.305915 28438 ts_manager.cc:194] Registered new tserver with Master: 36c5b9dd084c447185c1b17cc111a2c8 (127.27.185.193:33511)
I20260812 06:20:26.306391 28391 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010107465s
I20260812 06:20:26.307080 28438 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38164
I20260812 06:20:26.314958 28438 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38172:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:26.328649 28605 tablet_service.cc:1511] Processing CreateTablet for tablet 39df572e6a73400f8c572dfb99b2269e (DEFAULT_TABLE table=heavy-update-compaction-test [id=58322bb36bf74b1db8c80de6df17ab3d]), partition=
I20260812 06:20:26.329129 28605 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 39df572e6a73400f8c572dfb99b2269e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.331292 28690 tablet_bootstrap.cc:492] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Bootstrap starting.
I20260812 06:20:26.332188 28690 tablet_bootstrap.cc:654] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.333518 28690 tablet_bootstrap.cc:492] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: No bootstrap required, opened a new log
I20260812 06:20:26.333629 28690 ts_tablet_manager.cc:1403] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.334081 28690 raft_consensus.cc:359] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c5b9dd084c447185c1b17cc111a2c8" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33511 } }
I20260812 06:20:26.334184 28690 raft_consensus.cc:385] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.334247 28690 raft_consensus.cc:740] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 36c5b9dd084c447185c1b17cc111a2c8, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.334411 28690 consensus_queue.cc:260] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [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: "36c5b9dd084c447185c1b17cc111a2c8" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33511 } }
I20260812 06:20:26.334499 28690 raft_consensus.cc:399] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.334528 28690 raft_consensus.cc:493] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.334594 28690 raft_consensus.cc:3060] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.335351 28690 raft_consensus.cc:515] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c5b9dd084c447185c1b17cc111a2c8" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33511 } }
I20260812 06:20:26.335477 28690 leader_election.cc:304] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [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: 36c5b9dd084c447185c1b17cc111a2c8; no voters: 
I20260812 06:20:26.335740 28690 leader_election.cc:290] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.336068 28693 raft_consensus.cc:2804] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.336206 28690 ts_tablet_manager.cc:1434] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:26.336349 28693 raft_consensus.cc:697] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 1 LEADER]: Becoming Leader. State: Replica: 36c5b9dd084c447185c1b17cc111a2c8, State: Running, Role: LEADER
I20260812 06:20:26.336477 28669 heartbeater.cc:499] Master 127.27.185.254:36977 was elected leader, sending a full tablet report...
I20260812 06:20:26.336511 28693 consensus_queue.cc:237] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [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: "36c5b9dd084c447185c1b17cc111a2c8" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33511 } }
I20260812 06:20:26.339159 28438 catalog_manager.cc:5719] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 36c5b9dd084c447185c1b17cc111a2c8 (127.27.185.193). New cstate: current_term: 1 leader_uuid: "36c5b9dd084c447185c1b17cc111a2c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c5b9dd084c447185c1b17cc111a2c8" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33511 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.401775 28391 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.025s	sys 0.004s
I20260812 06:20:26.546698 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushMRSOp(39df572e6a73400f8c572dfb99b2269e): perf score=19.054940
I20260812 06:20:26.739528 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushMRSOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.192s	user 0.131s	sys 0.056s Metrics: {"bytes_written":12553638,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1437,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48351,"lbm_writes_lt_1ms":763,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":177,"threads_started":1,"update_count":1530}
I20260812 06:20:26.740618 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling LogGCOp(39df572e6a73400f8c572dfb99b2269e): free 20743880 bytes of WAL
I20260812 06:20:26.740921 28571 log_reader.cc:385] T 39df572e6a73400f8c572dfb99b2269e: removed 2 log segments from log reader
I20260812 06:20:26.741006 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000001 (ops 1-6)
I20260812 06:20:26.741063 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000002 (ops 7-11)
I20260812 06:20:26.746830 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: LogGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:26.747236 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=6.157687
I20260812 06:20:26.779285 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.032s	user 0.014s	sys 0.015s Metrics: {"bytes_written":7466649,"delete_count":0,"lbm_write_time_us":11326,"lbm_writes_lt_1ms":185,"reinsert_count":0,"update_count":910}
I20260812 06:20:26.779810 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:26.961091 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.181s	user 0.114s	sys 0.065s Metrics: {"cfile_cache_miss":520,"cfile_cache_miss_bytes":24282409,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":13876,"lbm_reads_lt_1ms":552,"lbm_write_time_us":30716,"lbm_writes_lt_1ms":531,"mutex_wait_us":49,"peak_mem_usage":61583096,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":361,"threads_started":5,"update_count":2440}
I20260812 06:20:26.961647 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=15.087375
I20260812 06:20:27.017637 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.056s	user 0.036s	sys 0.018s Metrics: {"bytes_written":16902197,"delete_count":0,"lbm_write_time_us":24541,"lbm_writes_lt_1ms":415,"reinsert_count":0,"update_count":2060}
I20260812 06:20:27.018286 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:27.030576 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.031035 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e): 16411394 bytes on disk
I20260812 06:20:27.031553 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.032112 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:27.248008 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.216s	user 0.135s	sys 0.069s Metrics: {"cfile_cache_miss":544,"cfile_cache_miss_bytes":25266984,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":409,"lbm_read_time_us":13584,"lbm_reads_lt_1ms":584,"lbm_write_time_us":34197,"lbm_writes_lt_1ms":555,"mutex_wait_us":42,"peak_mem_usage":64648704,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2560}
I20260812 06:20:27.248643 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:27.301486 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22465,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.301988 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:27.314286 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.314981 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:27.496233 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.181s	user 0.123s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1099,"lbm_read_time_us":11786,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33834,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:20:27.496733 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:27.553296 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.056s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22732,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.553785 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:27.565554 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.566041 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:27.731431 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.165s	user 0.133s	sys 0.024s 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":352,"lbm_read_time_us":12034,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32982,"lbm_writes_lt_1ms":543,"mutex_wait_us":86,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2500}
I20260812 06:20:27.731976 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:27.785703 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.054s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19599,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.786142 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:27.796847 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.797452 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:27.951179 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.154s	user 0.117s	sys 0.032s 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":943,"lbm_read_time_us":12939,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29749,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:20:27.951782 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=11.118625
I20260812 06:20:27.983322 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.031s	user 0.008s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13967,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.984025 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:28.002611 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6609,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.003170 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushMRSOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:28.054617 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushMRSOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.051s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1109,"drs_written":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2117,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:28.055553 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling LogGCOp(39df572e6a73400f8c572dfb99b2269e): free 120553405 bytes of WAL
I20260812 06:20:28.055827 28571 log_reader.cc:385] T 39df572e6a73400f8c572dfb99b2269e: removed 12 log segments from log reader
I20260812 06:20:28.055891 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000003 (ops 12-16)
I20260812 06:20:28.055933 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000004 (ops 17-21)
I20260812 06:20:28.055974 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000005 (ops 22-26)
I20260812 06:20:28.056080 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000006 (ops 27-31)
I20260812 06:20:28.056125 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000007 (ops 32-36)
I20260812 06:20:28.056188 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000008 (ops 37-40)
I20260812 06:20:28.056226 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000009 (ops 41-45)
I20260812 06:20:28.056288 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000010 (ops 46-50)
I20260812 06:20:28.056334 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000011 (ops 51-55)
I20260812 06:20:28.056372 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000012 (ops 56-60)
I20260812 06:20:28.056406 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000013 (ops 61-64)
I20260812 06:20:28.056438 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000014 (ops 65-69)
I20260812 06:20:28.092525 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: LogGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.037s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:20:28.093024 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=6.157687
I20260812 06:20:28.123294 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.030s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11958,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:28.123872 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e): 473 bytes on disk
I20260812 06:20:28.124430 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.124907 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:28.137447 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.137881 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:28.324862 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.187s	user 0.142s	sys 0.044s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":912,"lbm_read_time_us":13555,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39577,"lbm_writes_lt_1ms":743,"mutex_wait_us":580,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:20:28.325994 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:28.395939 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.070s	user 0.030s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":32580,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.396431 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=3.181125
I20260812 06:20:28.419528 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.023s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7095,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.419982 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:28.430614 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.431097 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:28.610644 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.179s	user 0.151s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":417,"lbm_read_time_us":12976,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40110,"lbm_writes_lt_1ms":643,"mutex_wait_us":103,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3000}
I20260812 06:20:28.611550 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:28.672343 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.060s	user 0.025s	sys 0.033s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27207,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.673116 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:28.691607 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.692204 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:28.857251 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.165s	user 0.129s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":11187,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31958,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38272,"update_count":2500}
I20260812 06:20:28.857854 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:28.915843 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.058s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25096,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.916399 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:28.928319 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.928800 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:29.101922 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.173s	user 0.112s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":13780,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33043,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:29.102545 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:29.162758 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.060s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19081,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.163316 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:29.175315 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.175887 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:29.363235 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.187s	user 0.126s	sys 0.052s 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":723,"lbm_read_time_us":13449,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31201,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:20:29.363807 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:29.430634 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.067s	user 0.029s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22375,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.431182 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:29.441788 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.442219 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushMRSOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:29.470340 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushMRSOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.028s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1431,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:29.471045 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e): 447 bytes on disk
I20260812 06:20:29.471414 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: UndoDeltaBlockGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.471855 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:29.643419 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.171s	user 0.126s	sys 0.045s 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":875,"lbm_read_time_us":13128,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27428,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:29.644166 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling LogGCOp(39df572e6a73400f8c572dfb99b2269e): free 120553329 bytes of WAL
I20260812 06:20:29.644419 28571 log_reader.cc:385] T 39df572e6a73400f8c572dfb99b2269e: removed 12 log segments from log reader
I20260812 06:20:29.644501 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000015 (ops 70-74)
I20260812 06:20:29.644569 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000016 (ops 75-79)
I20260812 06:20:29.644625 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000017 (ops 80-84)
I20260812 06:20:29.644678 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000018 (ops 85-89)
I20260812 06:20:29.644729 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000019 (ops 90-94)
I20260812 06:20:29.644799 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000020 (ops 95-99)
I20260812 06:20:29.644877 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000021 (ops 100-104)
I20260812 06:20:29.644928 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000022 (ops 105-108)
I20260812 06:20:29.644994 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000023 (ops 109-113)
I20260812 06:20:29.645054 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000024 (ops 114-118)
I20260812 06:20:29.645099 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000025 (ops 119-122)
I20260812 06:20:29.645143 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000026 (ops 123-127)
I20260812 06:20:29.676611 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: LogGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:29.677194 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=15.087375
I20260812 06:20:29.741918 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.064s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20672,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:29.742449 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=6.157687
I20260812 06:20:29.762171 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.020s	user 0.014s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":7914,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:29.762642 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:29.967290 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.204s	user 0.111s	sys 0.093s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":928,"lbm_read_time_us":17841,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34757,"lbm_writes_lt_1ms":643,"mutex_wait_us":297,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":3000}
I20260812 06:20:29.967960 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:30.027489 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.059s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":25345,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.028146 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:30.039255 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.039999 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:30.223839 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.184s	user 0.121s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":12924,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31388,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:20:30.224525 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:30.287290 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.063s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19780,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.287909 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:30.299028 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.299486 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:30.478509 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.179s	user 0.125s	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":175,"lbm_read_time_us":13418,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29952,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.479297 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:30.528678 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.049s	user 0.017s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21839,"lbm_writes_lt_1ms":403,"mutex_wait_us":28,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.529211 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:30.555543 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.026s	user 0.008s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.556104 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:30.746670 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.190s	user 0.142s	sys 0.044s 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":1262,"lbm_read_time_us":14109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33301,"lbm_writes_lt_1ms":543,"mutex_wait_us":612,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:20:30.747423 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:30.803229 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.056s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.803786 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:30.815630 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.816125 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:30.989871 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.174s	user 0.114s	sys 0.052s 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":1020,"lbm_read_time_us":11532,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27293,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:20:30.990634 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:31.050640 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.060s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24404,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.051209 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:31.066359 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.066844 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushMRSOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:31.096748 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushMRSOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1285,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1902,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:31.097450 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling LogGCOp(39df572e6a73400f8c572dfb99b2269e): free 120553684 bytes of WAL
I20260812 06:20:31.097729 28571 log_reader.cc:385] T 39df572e6a73400f8c572dfb99b2269e: removed 12 log segments from log reader
I20260812 06:20:31.097790 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000027 (ops 128-132)
I20260812 06:20:31.097841 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000028 (ops 133-137)
I20260812 06:20:31.097877 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000029 (ops 138-142)
I20260812 06:20:31.097900 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000030 (ops 143-147)
I20260812 06:20:31.097922 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000031 (ops 148-152)
I20260812 06:20:31.097954 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000032 (ops 153-156)
I20260812 06:20:31.097982 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000033 (ops 157-161)
I20260812 06:20:31.098012 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000034 (ops 162-166)
I20260812 06:20:31.098045 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000035 (ops 167-170)
I20260812 06:20:31.098074 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000036 (ops 171-175)
I20260812 06:20:31.098102 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000037 (ops 176-180)
I20260812 06:20:31.098129 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000038 (ops 181-185)
I20260812 06:20:31.128554 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: LogGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:31.129088 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=5.165500
I20260812 06:20:31.151108 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.022s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6441038,"delete_count":0,"lbm_write_time_us":9009,"lbm_writes_lt_1ms":160,"reinsert_count":0,"update_count":785}
I20260812 06:20:31.151634 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling LogGCOp(39df572e6a73400f8c572dfb99b2269e): free 12017952 bytes of WAL
I20260812 06:20:31.151885 28571 log_reader.cc:385] T 39df572e6a73400f8c572dfb99b2269e: removed 1 log segments from log reader
I20260812 06:20:31.151948 28571 log.cc:1079] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/39df572e6a73400f8c572dfb99b2269e/wal-000000039 (ops 186-190)
I20260812 06:20:31.155344 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: LogGCOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:31.155712 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:31.166050 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":1764227,"delete_count":0,"lbm_write_time_us":3159,"lbm_writes_lt_1ms":46,"reinsert_count":0,"update_count":215}
I20260812 06:20:31.166672 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:31.414233 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.247s	user 0.171s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":320,"lbm_read_time_us":16687,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46286,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17024,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:31.415143 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=14.095187
I20260812 06:20:31.449503 28391 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.048s	user 1.839s	sys 0.169s
I20260812 06:20:31.459831 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.044s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21939,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.460371 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e): perf score=2.188937
I20260812 06:20:31.477761 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: FlushDeltaMemStoresOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.478286 28670 maintenance_manager.cc:419] P 36c5b9dd084c447185c1b17cc111a2c8: Scheduling MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e): perf score=1.000000
I20260812 06:20:31.500663 28391 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.050s	user 0.002s	sys 0.000s
I20260812 06:20:31.501358 28391 tablet_server.cc:179] TabletServer@127.27.185.193:0 shutting down...
I20260812 06:20:31.622236 28571 maintenance_manager.cc:643] P 36c5b9dd084c447185c1b17cc111a2c8: MajorDeltaCompactionOp(39df572e6a73400f8c572dfb99b2269e) complete. Timing: real 0.144s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":11179,"lbm_reads_lt_1ms":518,"lbm_write_time_us":25233,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:20:31.623097 28391 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.623545 28391 tablet_replica.cc:333] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8: stopping tablet replica
I20260812 06:20:31.623786 28391 raft_consensus.cc:2243] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.624027 28391 raft_consensus.cc:2272] T 39df572e6a73400f8c572dfb99b2269e P 36c5b9dd084c447185c1b17cc111a2c8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.641566 28391 tablet_server.cc:196] TabletServer@127.27.185.193:0 shutdown complete.
I20260812 06:20:31.668426 28391 master.cc:562] Master@127.27.185.254:36977 shutting down...
I20260812 06:20:31.671849 28391 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.672040 28391 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.672115 28391 tablet_replica.cc:333] T 00000000000000000000000000000000 P 423eb757c8ea4c69a1f36dcc6fbf1267: stopping tablet replica
I20260812 06:20:31.684623 28391 master.cc:584] Master@127.27.185.254:36977 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5731 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:31.778893 28391 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.185.254:40301
I20260812 06:20:31.779326 28391 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:31.781386 28724 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.781505 28728 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.781423 28730 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:31.781502 28391 server_base.cc:1061] running on GCE node
I20260812 06:20:31.781774 28391 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:31.781817 28391 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:31.781833 28391 hybrid_clock.cc:648] HybridClock initialized: now 1786515631781834 us; error 0 us; skew 500 ppm
I20260812 06:20:31.782657 28391 webserver.cc:533] Webserver started at http://127.27.185.254:36683/ using document root <none> and password file <none>
I20260812 06:20:31.782792 28391 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:31.782836 28391 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:31.782902 28391 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:31.783250 28391 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/master-0-root/instance:
uuid: "5acdef5c923341ec968253befb2ed39c"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-ffrd"
I20260812 06:20:31.784747 28391 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:31.785880 28739 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.786144 28391 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:31.786211 28391 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/master-0-root
uuid: "5acdef5c923341ec968253befb2ed39c"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-ffrd"
I20260812 06:20:31.786315 28391 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:31.796391 28391 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.796842 28391 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.801558 28391 rpc_server.cc:307] RPC server started. Bound to: 127.27.185.254:40301
I20260812 06:20:31.804801 28825 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.185.254:40301 every 8 connection(s)
I20260812 06:20:31.808646 28826 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:31.823258 28826 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c: Bootstrap starting.
I20260812 06:20:31.824100 28826 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.825263 28826 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c: No bootstrap required, opened a new log
I20260812 06:20:31.825650 28826 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER }
I20260812 06:20:31.825743 28826 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.825765 28826 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5acdef5c923341ec968253befb2ed39c, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.825874 28826 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [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: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER }
I20260812 06:20:31.825932 28826 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.825955 28826 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.825990 28826 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.826701 28826 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER }
I20260812 06:20:31.826817 28826 leader_election.cc:304] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [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: 5acdef5c923341ec968253befb2ed39c; no voters: 
I20260812 06:20:31.826982 28826 leader_election.cc:290] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.827138 28829 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.827378 28829 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 1 LEADER]: Becoming Leader. State: Replica: 5acdef5c923341ec968253befb2ed39c, State: Running, Role: LEADER
I20260812 06:20:31.827497 28826 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:31.827546 28829 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [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: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER }
I20260812 06:20:31.828018 28830 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5acdef5c923341ec968253befb2ed39c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER } }
I20260812 06:20:31.828131 28830 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.828033 28833 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5acdef5c923341ec968253befb2ed39c. Latest consensus state: current_term: 1 leader_uuid: "5acdef5c923341ec968253befb2ed39c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5acdef5c923341ec968253befb2ed39c" member_type: VOTER } }
I20260812 06:20:31.828202 28833 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.828836 28838 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:31.829540 28838 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:31.829787 28391 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:31.831406 28838 catalog_manager.cc:1383] Generated new cluster ID: 868e5f2014b64426a508b0a6f2734371
I20260812 06:20:31.831501 28838 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:31.854185 28838 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:31.854797 28838 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:31.871140 28838 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c: Generated new TSK 0
I20260812 06:20:31.871330 28838 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:31.894452 28391 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:31.896585 28858 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.896620 28857 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.896600 28862 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:31.896890 28391 server_base.cc:1061] running on GCE node
I20260812 06:20:31.897096 28391 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:31.897140 28391 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:31.897156 28391 hybrid_clock.cc:648] HybridClock initialized: now 1786515631897156 us; error 0 us; skew 500 ppm
I20260812 06:20:31.897989 28391 webserver.cc:533] Webserver started at http://127.27.185.193:36543/ using document root <none> and password file <none>
I20260812 06:20:31.898128 28391 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:31.898172 28391 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:31.898224 28391 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:31.898581 28391 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/instance:
uuid: "90b4140a75214b0ba7b9e9661828ff09"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-ffrd"
I20260812 06:20:31.900343 28391 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:31.901343 28870 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.901643 28391 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:31.901705 28391 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root
uuid: "90b4140a75214b0ba7b9e9661828ff09"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-ffrd"
I20260812 06:20:31.901762 28391 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:31.918864 28391 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.919257 28391 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.919538 28391 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:31.920079 28391 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:31.920120 28391 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.920186 28391 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:31.920226 28391 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.924803 28391 rpc_server.cc:307] RPC server started. Bound to: 127.27.185.193:33135
I20260812 06:20:31.924831 28966 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.185.193:33135 every 8 connection(s)
I20260812 06:20:31.933954 28967 heartbeater.cc:344] Connected to a master server at 127.27.185.254:40301
I20260812 06:20:31.934082 28967 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:31.934324 28967 heartbeater.cc:507] Master 127.27.185.254:40301 requested a full tablet report, sending...
I20260812 06:20:31.935007 28767 ts_manager.cc:194] Registered new tserver with Master: 90b4140a75214b0ba7b9e9661828ff09 (127.27.185.193:33135)
I20260812 06:20:31.935348 28391 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010062861s
I20260812 06:20:31.935768 28767 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59422
I20260812 06:20:31.942612 28767 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59424:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:31.951699 28914 tablet_service.cc:1511] Processing CreateTablet for tablet 5110f8a37b304eabba2417a1e1d69404 (DEFAULT_TABLE table=heavy-update-compaction-test [id=55b762163b40434c8bdf8583c214014c]), partition=
I20260812 06:20:31.952023 28914 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5110f8a37b304eabba2417a1e1d69404. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:31.954381 28982 tablet_bootstrap.cc:492] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Bootstrap starting.
I20260812 06:20:31.955264 28982 tablet_bootstrap.cc:654] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.956444 28982 tablet_bootstrap.cc:492] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: No bootstrap required, opened a new log
I20260812 06:20:31.956552 28982 ts_tablet_manager.cc:1403] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:31.957135 28982 raft_consensus.cc:359] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90b4140a75214b0ba7b9e9661828ff09" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33135 } }
I20260812 06:20:31.957244 28982 raft_consensus.cc:385] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.957295 28982 raft_consensus.cc:740] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 90b4140a75214b0ba7b9e9661828ff09, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.957453 28982 consensus_queue.cc:260] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [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: "90b4140a75214b0ba7b9e9661828ff09" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33135 } }
I20260812 06:20:31.957556 28982 raft_consensus.cc:399] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.957604 28982 raft_consensus.cc:493] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.957659 28982 raft_consensus.cc:3060] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.958380 28982 raft_consensus.cc:515] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90b4140a75214b0ba7b9e9661828ff09" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33135 } }
I20260812 06:20:31.958539 28982 leader_election.cc:304] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [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: 90b4140a75214b0ba7b9e9661828ff09; no voters: 
I20260812 06:20:31.958760 28982 leader_election.cc:290] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.958916 28984 raft_consensus.cc:2804] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.959123 28982 ts_tablet_manager.cc:1434] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:31.959148 28967 heartbeater.cc:499] Master 127.27.185.254:40301 was elected leader, sending a full tablet report...
I20260812 06:20:31.959179 28984 raft_consensus.cc:697] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 1 LEADER]: Becoming Leader. State: Replica: 90b4140a75214b0ba7b9e9661828ff09, State: Running, Role: LEADER
I20260812 06:20:31.959406 28984 consensus_queue.cc:237] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [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: "90b4140a75214b0ba7b9e9661828ff09" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33135 } }
I20260812 06:20:31.960727 28767 catalog_manager.cc:5719] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 reported cstate change: term changed from 0 to 1, leader changed from <none> to 90b4140a75214b0ba7b9e9661828ff09 (127.27.185.193). New cstate: current_term: 1 leader_uuid: "90b4140a75214b0ba7b9e9661828ff09" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90b4140a75214b0ba7b9e9661828ff09" member_type: VOTER last_known_addr { host: "127.27.185.193" port: 33135 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:32.022917 28391 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.015s	sys 0.008s
I20260812 06:20:32.175976 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushMRSOp(5110f8a37b304eabba2417a1e1d69404): perf score=19.054940
I20260812 06:20:32.323746 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushMRSOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.148s	user 0.109s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":738,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39331,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":28416,"update_count":1500}
I20260812 06:20:32.324468 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 20743880 bytes of WAL
I20260812 06:20:32.324733 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 2 log segments from log reader
I20260812 06:20:32.324795 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000001 (ops 1-6)
I20260812 06:20:32.324831 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000002 (ops 7-11)
I20260812 06:20:32.330781 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:32.331144 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:32.347076 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.347656 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:32.485163 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.137s	user 0.092s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":564,"lbm_read_time_us":9451,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25592,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"thread_start_us":354,"threads_started":5,"update_count":2000}
I20260812 06:20:32.485764 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404): 16411392 bytes on disk
I20260812 06:20:32.486302 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.486713 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:32.524847 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.038s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":16792,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.525399 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:32.542490 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.017s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.543066 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:32.676869 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.134s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":8978,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26035,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:20:32.678102 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:32.725389 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.047s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17135,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.725991 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:32.741505 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.742050 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:32.875102 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.133s	user 0.081s	sys 0.052s 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":161,"lbm_read_time_us":10891,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25011,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:20:32.875674 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:32.918784 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.043s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14436,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.919330 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:32.930178 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.930625 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:33.089813 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.159s	user 0.087s	sys 0.071s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":12310,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26269,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.090431 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:33.133011 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.042s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.133468 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:33.145242 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.145951 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:33.279762 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.134s	user 0.101s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":813,"lbm_read_time_us":10236,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26181,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:20:33.280349 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:33.324295 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.044s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16283,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.324803 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:33.336182 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) 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:20:33.336820 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:33.464784 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.128s	user 0.095s	sys 0.033s 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":988,"lbm_read_time_us":10447,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24035,"lbm_writes_lt_1ms":443,"mutex_wait_us":370,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:20:33.465540 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:33.521482 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.056s	user 0.032s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19010,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.522136 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:33.542063 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.020s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.542647 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushMRSOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:33.576474 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushMRSOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.034s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1421,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1612,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:33.577198 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 112239310 bytes of WAL
I20260812 06:20:33.577414 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 11 log segments from log reader
I20260812 06:20:33.577476 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000003 (ops 12-16)
I20260812 06:20:33.577531 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000004 (ops 17-21)
I20260812 06:20:33.577591 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000005 (ops 22-26)
I20260812 06:20:33.577634 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000006 (ops 27-31)
I20260812 06:20:33.577674 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000007 (ops 32-36)
I20260812 06:20:33.577713 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000008 (ops 37-41)
I20260812 06:20:33.577751 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000009 (ops 42-46)
I20260812 06:20:33.577798 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000010 (ops 47-51)
I20260812 06:20:33.577837 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000011 (ops 52-56)
I20260812 06:20:33.577877 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000012 (ops 57-60)
I20260812 06:20:33.577915 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000013 (ops 61-65)
I20260812 06:20:33.603771 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:33.604195 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404): 447 bytes on disk
I20260812 06:20:33.604816 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:20:33.605501 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=3.181125
I20260812 06:20:33.621492 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.016s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:33.621937 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:33.631781 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:33.632258 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:33.879551 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.247s	user 0.124s	sys 0.108s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1825,"dirs.run_cpu_time_us":1896,"dirs.run_wall_time_us":13556,"lbm_read_time_us":17510,"lbm_reads_lt_1ms":674,"lbm_write_time_us":44458,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":654,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":3000}
I20260812 06:20:33.880316 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=14.095187
I20260812 06:20:33.937153 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.057s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25084,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.937891 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:33.956748 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.019s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.957404 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:34.246804 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.289s	user 0.215s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":19987,"lbm_reads_lt_1ms":572,"lbm_write_time_us":41691,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":127,"threads_started":2,"update_count":2500}
I20260812 06:20:34.247591 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=22.032687
I20260812 06:20:34.349077 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.101s	user 0.082s	sys 0.014s Metrics: {"bytes_written":24614724,"delete_count":0,"lbm_write_time_us":42192,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:20:34.349710 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=6.157687
I20260812 06:20:34.390584 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.041s	user 0.013s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9243,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:34.391062 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:34.406347 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.406994 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:34.684721 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.277s	user 0.201s	sys 0.070s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41184455,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":614,"lbm_read_time_us":23426,"lbm_reads_lt_1ms":973,"lbm_write_time_us":52692,"lbm_writes_lt_1ms":943,"mutex_wait_us":1,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":4500}
I20260812 06:20:34.685410 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=19.056125
I20260812 06:20:34.755923 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.070s	user 0.043s	sys 0.013s Metrics: {"bytes_written":20922554,"delete_count":0,"lbm_write_time_us":26577,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:20:34.756393 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=6.157687
I20260812 06:20:34.785233 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.029s	user 0.018s	sys 0.008s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":11052,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:34.785825 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:34.998128 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.212s	user 0.176s	sys 0.036s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979513,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":836,"lbm_read_time_us":14020,"lbm_reads_lt_1ms":764,"lbm_write_time_us":47726,"lbm_writes_lt_1ms":743,"mutex_wait_us":359,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3500}
I20260812 06:20:34.998816 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=18.063937
I20260812 06:20:35.069141 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.070s	user 0.054s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30827,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:35.069828 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:35.096719 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.027s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5933,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.097254 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:35.108052 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.108561 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushMRSOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:35.139590 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushMRSOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.031s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1312,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1631,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:35.140450 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 121006437 bytes of WAL
I20260812 06:20:35.140736 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 12 log segments from log reader
I20260812 06:20:35.140820 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000014 (ops 66-70)
I20260812 06:20:35.140879 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000015 (ops 71-74)
I20260812 06:20:35.140934 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000016 (ops 75-79)
I20260812 06:20:35.141010 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000017 (ops 80-84)
I20260812 06:20:35.141049 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000018 (ops 85-89)
I20260812 06:20:35.141088 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000019 (ops 90-94)
I20260812 06:20:35.141124 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000020 (ops 95-99)
I20260812 06:20:35.141161 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000021 (ops 100-104)
I20260812 06:20:35.141198 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000022 (ops 105-109)
I20260812 06:20:35.141235 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000023 (ops 110-114)
I20260812 06:20:35.141271 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000024 (ops 115-119)
I20260812 06:20:35.141309 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000025 (ops 120-124)
I20260812 06:20:35.170105 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:35.170610 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=3.181125
I20260812 06:20:35.189982 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7331,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:35.190413 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 11564877 bytes of WAL
I20260812 06:20:35.190618 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 1 log segments from log reader
I20260812 06:20:35.190663 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000026 (ops 125-128)
I20260812 06:20:35.193053 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:35.193352 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:35.204631 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3736,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.205288 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:35.459779 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.254s	user 0.198s	sys 0.056s Metrics: {"cfile_cache_miss":935,"cfile_cache_miss_bytes":41184682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":282,"lbm_read_time_us":20400,"lbm_reads_lt_1ms":975,"lbm_write_time_us":54984,"lbm_writes_lt_1ms":943,"mutex_wait_us":46,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":22528,"thread_start_us":76,"threads_started":1,"update_count":4500}
I20260812 06:20:35.460481 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404): 473 bytes on disk
I20260812 06:20:35.460992 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.461576 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=18.063937
I20260812 06:20:35.532826 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.071s	user 0.036s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26762,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1005952,"update_count":2500}
I20260812 06:20:35.533576 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:35.551635 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.552081 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:35.780323 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.228s	user 0.136s	sys 0.088s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":13824,"lbm_reads_lt_1ms":668,"lbm_write_time_us":37033,"lbm_writes_lt_1ms":643,"mutex_wait_us":303,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":3000}
I20260812 06:20:35.780997 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=18.063937
I20260812 06:20:35.840512 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.059s	user 0.030s	sys 0.018s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":24275,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:35.841034 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:36.020247 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.179s	user 0.118s	sys 0.061s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774568,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":558,"lbm_read_time_us":14777,"lbm_reads_lt_1ms":563,"lbm_write_time_us":31761,"lbm_writes_lt_1ms":543,"mutex_wait_us":316,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:20:36.021617 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=14.095187
I20260812 06:20:36.079277 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.056s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20517,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.079852 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:36.091315 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.091914 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:36.277526 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.185s	user 0.126s	sys 0.053s 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":1443,"lbm_read_time_us":13387,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28762,"lbm_writes_lt_1ms":543,"mutex_wait_us":637,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:20:36.278090 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=14.095187
I20260812 06:20:36.347216 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.069s	user 0.047s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.347782 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:36.358573 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.359102 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:36.538537 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.179s	user 0.109s	sys 0.070s 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":1151,"lbm_read_time_us":13475,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30671,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:20:36.539139 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=11.118625
I20260812 06:20:36.568756 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.029s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13363,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:36.569252 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:36.582072 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.582675 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:36.719400 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.137s	user 0.106s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":9666,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25461,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:36.720168 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=10.126437
I20260812 06:20:36.759903 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17076,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:36.760438 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:36.771097 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.771919 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushMRSOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:36.805620 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushMRSOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.033s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1406,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2129,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:36.806257 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 117302827 bytes of WAL
I20260812 06:20:36.806495 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 12 log segments from log reader
I20260812 06:20:36.806540 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000027 (ops 129-133)
I20260812 06:20:36.806568 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000028 (ops 134-138)
I20260812 06:20:36.806622 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000029 (ops 139-142)
I20260812 06:20:36.806655 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000030 (ops 143-147)
I20260812 06:20:36.806692 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000031 (ops 148-152)
I20260812 06:20:36.806736 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000032 (ops 153-157)
I20260812 06:20:36.806783 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000033 (ops 158-162)
I20260812 06:20:36.806820 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000034 (ops 163-166)
I20260812 06:20:36.806864 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000035 (ops 167-171)
I20260812 06:20:36.806900 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000036 (ops 172-176)
I20260812 06:20:36.806936 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000037 (ops 177-181)
I20260812 06:20:36.806972 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000038 (ops 182-186)
I20260812 06:20:36.837518 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:36.838089 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404): 482 bytes on disk
I20260812 06:20:36.838619 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: UndoDeltaBlockGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:36.839296 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=3.181125
I20260812 06:20:36.856933 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7506,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:36.857427 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling LogGCOp(5110f8a37b304eabba2417a1e1d69404): free 11564891 bytes of WAL
I20260812 06:20:36.857631 28878 log_reader.cc:385] T 5110f8a37b304eabba2417a1e1d69404: removed 1 log segments from log reader
I20260812 06:20:36.857673 28878 log.cc:1079] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: Deleting log segment in path: /tmp/dist-test-taskhoOAwe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515626036782-28391-0/minicluster-data/ts-0-root/wals/5110f8a37b304eabba2417a1e1d69404/wal-000000039 (ops 187-190)
I20260812 06:20:36.860049 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: LogGCOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:36.860342 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:36.871343 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.871937 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:37.056663 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.184s	user 0.140s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":517,"lbm_read_time_us":14365,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37038,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":100,"threads_started":1,"update_count":3000}
I20260812 06:20:37.057493 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=14.095187
I20260812 06:20:37.092320 28391 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.069s	user 1.901s	sys 0.175s
I20260812 06:20:37.106024 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23193,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.106644 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404): perf score=2.188937
I20260812 06:20:37.124538 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: FlushDeltaMemStoresOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.018s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.125304 28968 maintenance_manager.cc:419] P 90b4140a75214b0ba7b9e9661828ff09: Scheduling MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404): perf score=1.000000
I20260812 06:20:37.129279 28391 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.036s	user 0.003s	sys 0.000s
I20260812 06:20:37.129834 28391 tablet_server.cc:179] TabletServer@127.27.185.193:0 shutting down...
I20260812 06:20:37.255086 28878 maintenance_manager.cc:643] P 90b4140a75214b0ba7b9e9661828ff09: MajorDeltaCompactionOp(5110f8a37b304eabba2417a1e1d69404) complete. Timing: real 0.130s	user 0.092s	sys 0.037s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":8872,"lbm_reads_lt_1ms":518,"lbm_write_time_us":25130,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":644736,"update_count":2500}
I20260812 06:20:37.256039 28391 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:37.256287 28391 tablet_replica.cc:333] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09: stopping tablet replica
I20260812 06:20:37.256426 28391 raft_consensus.cc:2243] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:37.256605 28391 raft_consensus.cc:2272] T 5110f8a37b304eabba2417a1e1d69404 P 90b4140a75214b0ba7b9e9661828ff09 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:37.264832 28391 tablet_server.cc:196] TabletServer@127.27.185.193:0 shutdown complete.
I20260812 06:20:37.301352 28391 master.cc:562] Master@127.27.185.254:40301 shutting down...
I20260812 06:20:37.305190 28391 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:37.305394 28391 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:37.305487 28391 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5acdef5c923341ec968253befb2ed39c: stopping tablet replica
I20260812 06:20:37.318089 28391 master.cc:584] Master@127.27.185.254:40301 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5632 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11365 ms total)

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