[==========] 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:17:15.873452 13200 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.228.62:45473
I20260812 06:17:15.874545 13200 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:17:15.875211 13200 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:15.881994 13209 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:17:15.882164 13200 server_base.cc:1061] running on GCE node
W20260812 06:17:15.881994 13213 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:17:15.882414 13211 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:17:15.882926 13200 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:15.883055 13200 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:17:15.883123 13200 hybrid_clock.cc:648] HybridClock initialized: now 1786515435883120 us; error 0 us; skew 500 ppm
I20260812 06:17:15.885056 13200 webserver.cc:533] Webserver started at http://127.12.228.62:39793/ using document root <none> and password file <none>
I20260812 06:17:15.885649 13200 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:15.885741 13200 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:15.886009 13200 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:15.887784 13200 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/master-0-root/instance:
uuid: "f006c4a4ab6549fbabfa416393330cee"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-x4qh"
I20260812 06:17:15.891269 13200 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:15.893296 13225 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:17:15.894239 13200 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:15.894375 13200 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/master-0-root
uuid: "f006c4a4ab6549fbabfa416393330cee"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-x4qh"
I20260812 06:17:15.894481 13200 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-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:17:15.920672 13200 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:15.921384 13200 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:17:15.921574 13200 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:15.929306 13200 rpc_server.cc:307] RPC server started. Bound to: 127.12.228.62:45473
I20260812 06:17:15.929366 13305 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.228.62:45473 every 8 connection(s)
I20260812 06:17:15.932003 13307 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:17:15.938215 13307 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: Bootstrap starting.
I20260812 06:17:15.941012 13307 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.942030 13307 log.cc:826] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:15.943907 13307 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: No bootstrap required, opened a new log
I20260812 06:17:15.946785 13307 raft_consensus.cc:359] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER }
I20260812 06:17:15.946956 13307 raft_consensus.cc:385] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.946997 13307 raft_consensus.cc:740] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f006c4a4ab6549fbabfa416393330cee, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.947580 13307 consensus_queue.cc:260] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [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: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER }
I20260812 06:17:15.947717 13307 raft_consensus.cc:399] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.947839 13307 raft_consensus.cc:493] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.947971 13307 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.949195 13307 raft_consensus.cc:515] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER }
I20260812 06:17:15.949625 13307 leader_election.cc:304] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [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: f006c4a4ab6549fbabfa416393330cee; no voters: 
I20260812 06:17:15.949978 13307 leader_election.cc:290] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.950158 13310 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.950452 13310 raft_consensus.cc:697] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 1 LEADER]: Becoming Leader. State: Replica: f006c4a4ab6549fbabfa416393330cee, State: Running, Role: LEADER
I20260812 06:17:15.950873 13310 consensus_queue.cc:237] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [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: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER }
I20260812 06:17:15.951090 13307 sys_catalog.cc:565] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:15.952921 13316 sys_catalog.cc:455] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [sys.catalog]: SysCatalogTable state changed. Reason: New leader f006c4a4ab6549fbabfa416393330cee. Latest consensus state: current_term: 1 leader_uuid: "f006c4a4ab6549fbabfa416393330cee" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER } }
I20260812 06:17:15.953058 13316 sys_catalog.cc:458] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.952935 13315 sys_catalog.cc:455] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f006c4a4ab6549fbabfa416393330cee" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f006c4a4ab6549fbabfa416393330cee" member_type: VOTER } }
I20260812 06:17:15.953137 13315 sys_catalog.cc:458] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.953493 13200 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:15.955606 13335 catalog_manager.cc:1594] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:15.955694 13335 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:15.955767 13333 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:15.956490 13333 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:15.961720 13333 catalog_manager.cc:1383] Generated new cluster ID: 913d590cf76a454ca7f7a2005bceabcc
I20260812 06:17:15.961807 13333 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:15.980993 13333 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:15.981902 13333 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:15.998008 13333 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: Generated new TSK 0
I20260812 06:17:15.998785 13333 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:16.018280 13200 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:16.021502 13344 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:17:16.021611 13200 server_base.cc:1061] running on GCE node
W20260812 06:17:16.021502 13341 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:17:16.021713 13342 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:17:16.022001 13200 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:16.022050 13200 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:17:16.022066 13200 hybrid_clock.cc:648] HybridClock initialized: now 1786515436022066 us; error 0 us; skew 500 ppm
I20260812 06:17:16.023169 13200 webserver.cc:533] Webserver started at http://127.12.228.1:42461/ using document root <none> and password file <none>
I20260812 06:17:16.023363 13200 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:16.023491 13200 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:16.023602 13200 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:16.024044 13200 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/instance:
uuid: "7d195897fe894ae994388de788d04489"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-x4qh"
I20260812 06:17:16.025695 13200 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:16.026752 13358 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:17:16.027048 13200 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:16.027123 13200 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root
uuid: "7d195897fe894ae994388de788d04489"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-x4qh"
I20260812 06:17:16.027216 13200 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-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:17:16.043895 13200 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:16.044418 13200 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:16.044960 13200 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:16.045804 13200 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:16.045866 13200 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.045939 13200 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:16.045986 13200 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.052778 13200 rpc_server.cc:307] RPC server started. Bound to: 127.12.228.1:41107
I20260812 06:17:16.052937 13475 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.228.1:41107 every 8 connection(s)
I20260812 06:17:16.066272 13477 heartbeater.cc:344] Connected to a master server at 127.12.228.62:45473
I20260812 06:17:16.066532 13477 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:16.067024 13477 heartbeater.cc:507] Master 127.12.228.62:45473 requested a full tablet report, sending...
I20260812 06:17:16.068449 13249 ts_manager.cc:194] Registered new tserver with Master: 7d195897fe894ae994388de788d04489 (127.12.228.1:41107)
I20260812 06:17:16.068907 13200 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015321303s
I20260812 06:17:16.069653 13249 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57834
I20260812 06:17:16.079458 13249 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57836:
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:17:16.093142 13416 tablet_service.cc:1511] Processing CreateTablet for tablet 8525e652a3c54c169b9743dfb2d531ac (DEFAULT_TABLE table=heavy-update-compaction-test [id=bc4cb41c63804282bc31f96cbde7e623]), partition=
I20260812 06:17:16.093638 13416 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8525e652a3c54c169b9743dfb2d531ac. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:16.095875 13497 tablet_bootstrap.cc:492] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Bootstrap starting.
I20260812 06:17:16.097386 13497 tablet_bootstrap.cc:654] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:16.098608 13497 tablet_bootstrap.cc:492] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: No bootstrap required, opened a new log
I20260812 06:17:16.098691 13497 ts_tablet_manager.cc:1403] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:16.099231 13497 raft_consensus.cc:359] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d195897fe894ae994388de788d04489" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 41107 } }
I20260812 06:17:16.099334 13497 raft_consensus.cc:385] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:16.099357 13497 raft_consensus.cc:740] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7d195897fe894ae994388de788d04489, State: Initialized, Role: FOLLOWER
I20260812 06:17:16.099558 13497 consensus_queue.cc:260] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [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: "7d195897fe894ae994388de788d04489" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 41107 } }
I20260812 06:17:16.099649 13497 raft_consensus.cc:399] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:16.099678 13497 raft_consensus.cc:493] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:16.099749 13497 raft_consensus.cc:3060] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:16.100708 13497 raft_consensus.cc:515] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d195897fe894ae994388de788d04489" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 41107 } }
I20260812 06:17:16.100871 13497 leader_election.cc:304] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [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: 7d195897fe894ae994388de788d04489; no voters: 
I20260812 06:17:16.101104 13497 leader_election.cc:290] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:16.101212 13500 raft_consensus.cc:2804] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:16.101473 13500 raft_consensus.cc:697] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 1 LEADER]: Becoming Leader. State: Replica: 7d195897fe894ae994388de788d04489, State: Running, Role: LEADER
I20260812 06:17:16.101475 13497 ts_tablet_manager.cc:1434] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:16.101687 13477 heartbeater.cc:499] Master 127.12.228.62:45473 was elected leader, sending a full tablet report...
I20260812 06:17:16.101702 13500 consensus_queue.cc:237] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [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: "7d195897fe894ae994388de788d04489" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 41107 } }
I20260812 06:17:16.104324 13249 catalog_manager.cc:5719] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7d195897fe894ae994388de788d04489 (127.12.228.1). New cstate: current_term: 1 leader_uuid: "7d195897fe894ae994388de788d04489" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d195897fe894ae994388de788d04489" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 41107 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:16.167956 13200 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.016s	sys 0.008s
I20260812 06:17:16.304039 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac): perf score=19.054940
I20260812 06:17:16.496941 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.193s	user 0.150s	sys 0.037s Metrics: {"bytes_written":13784349,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":912,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":50468,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":792,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":329088,"thread_start_us":138,"threads_started":1,"update_count":1680}
I20260812 06:17:16.498128 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling LogGCOp(8525e652a3c54c169b9743dfb2d531ac): free 20743880 bytes of WAL
I20260812 06:17:16.498440 13366 log_reader.cc:385] T 8525e652a3c54c169b9743dfb2d531ac: removed 2 log segments from log reader
I20260812 06:17:16.498510 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000001 (ops 1-6)
I20260812 06:17:16.498569 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000002 (ops 7-11)
I20260812 06:17:16.504141 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: LogGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:16.504503 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=4.173312
I20260812 06:17:16.530929 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.026s	user 0.009s	sys 0.013s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":8650,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:17:16.531502 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac): 16411393 bytes on disk
I20260812 06:17:16.532153 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.532606 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:16.692540 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.160s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":509,"cfile_cache_miss_bytes":23831128,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":821,"lbm_read_time_us":12901,"lbm_reads_lt_1ms":541,"lbm_write_time_us":29508,"lbm_writes_lt_1ms":520,"mutex_wait_us":40,"peak_mem_usage":60091327,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":392,"threads_started":5,"update_count":2385}
I20260812 06:17:16.693329 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=11.118625
I20260812 06:17:16.731513 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.038s	user 0.022s	sys 0.015s Metrics: {"bytes_written":13251048,"delete_count":0,"lbm_write_time_us":16761,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:17:16.732019 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:16.748459 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.749013 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:16.879465 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.130s	user 0.109s	sys 0.020s Metrics: {"cfile_cache_miss":455,"cfile_cache_miss_bytes":21615834,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":836,"lbm_read_time_us":8077,"lbm_reads_lt_1ms":487,"lbm_write_time_us":27139,"lbm_writes_lt_1ms":466,"mutex_wait_us":284,"peak_mem_usage":52673517,"reinsert_count":0,"update_count":2115}
I20260812 06:17:16.880044 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=10.126437
I20260812 06:17:16.919209 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.039s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17250,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.919773 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:16.943244 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.023s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.943740 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:16.954273 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.954710 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:17.110702 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.156s	user 0.128s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774806,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":255,"lbm_read_time_us":12060,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29662,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:17:17.111322 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=11.118625
I20260812 06:17:17.148005 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.036s	user 0.036s	sys 0.000s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15764,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:17.148602 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:17.163439 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4536,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.164042 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:17.294214 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.130s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":7169,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25462,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:17:17.294698 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:17.354624 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.060s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21243,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.355105 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:17.366055 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.366564 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:17.527135 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.160s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":11393,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30013,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:17.531126 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=11.118625
I20260812 06:17:17.571821 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.040s	user 0.021s	sys 0.019s Metrics: {"bytes_written":13456166,"delete_count":0,"lbm_write_time_us":14590,"lbm_writes_lt_1ms":331,"reinsert_count":0,"update_count":1640}
I20260812 06:17:17.572463 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.196750
I20260812 06:17:17.589519 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.017s	user 0.000s	sys 0.008s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3735,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:17.590008 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:17.600633 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.601051 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:17.632735 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1398,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1555,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:17.633590 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling LogGCOp(8525e652a3c54c169b9743dfb2d531ac): free 112239331 bytes of WAL
I20260812 06:17:17.633832 13366 log_reader.cc:385] T 8525e652a3c54c169b9743dfb2d531ac: removed 11 log segments from log reader
I20260812 06:17:17.633877 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000003 (ops 12-16)
I20260812 06:17:17.633908 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000004 (ops 17-21)
I20260812 06:17:17.633973 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000005 (ops 22-26)
I20260812 06:17:17.634020 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000006 (ops 27-31)
I20260812 06:17:17.634061 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000007 (ops 32-36)
I20260812 06:17:17.634128 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000008 (ops 37-41)
I20260812 06:17:17.634166 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000009 (ops 42-46)
I20260812 06:17:17.634205 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000010 (ops 47-50)
I20260812 06:17:17.634246 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000011 (ops 51-55)
I20260812 06:17:17.634277 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000012 (ops 56-60)
I20260812 06:17:17.634308 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000013 (ops 61-65)
I20260812 06:17:17.658699 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: LogGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:17.659066 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac): 447 bytes on disk
I20260812 06:17:17.659572 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac) 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:17:17.660034 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=3.181125
I20260812 06:17:17.675766 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:17.676169 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:17.685640 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.686123 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:17.894997 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.209s	user 0.140s	sys 0.067s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979832,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":862,"lbm_read_time_us":14352,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38869,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:17:17.895756 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=15.087375
I20260812 06:17:17.967269 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.071s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":31593,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":408,"reinsert_count":0,"update_count":2050}
I20260812 06:17:17.967744 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=6.157687
I20260812 06:17:17.992156 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.024s	user 0.014s	sys 0.008s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":10036,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:17.992655 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:18.159680 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.167s	user 0.123s	sys 0.041s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":564,"lbm_read_time_us":12135,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34420,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3000}
I20260812 06:17:18.160365 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=15.087375
I20260812 06:17:18.208583 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.048s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21010,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:18.209064 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:18.222635 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.013s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4147,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:18.223153 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:18.380004 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.157s	user 0.119s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1304,"lbm_read_time_us":9806,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30201,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:18.380563 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:18.434758 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.054s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24350,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.435271 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:18.576247 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.141s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":179,"lbm_read_time_us":9581,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23775,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.576726 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:18.629127 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.052s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21508,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.629587 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:18.640200 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.640938 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:18.828239 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.187s	user 0.127s	sys 0.048s 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":225,"lbm_read_time_us":12084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31018,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:18.828882 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:18.877230 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.048s	user 0.035s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18675,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.877681 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:18.889024 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.889705 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:19.045303 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.155s	user 0.111s	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":1182,"lbm_read_time_us":12098,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30620,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:19.045835 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=10.126437
I20260812 06:17:19.089825 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.044s	user 0.032s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19942,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.090329 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:19.102871 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.103425 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:19.133594 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.030s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1312,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1774,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:19.134369 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling LogGCOp(8525e652a3c54c169b9743dfb2d531ac): free 133024376 bytes of WAL
I20260812 06:17:19.134627 13366 log_reader.cc:385] T 8525e652a3c54c169b9743dfb2d531ac: removed 13 log segments from log reader
I20260812 06:17:19.134707 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000014 (ops 66-70)
I20260812 06:17:19.134773 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000015 (ops 71-74)
I20260812 06:17:19.134843 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000016 (ops 75-79)
I20260812 06:17:19.134893 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000017 (ops 80-84)
I20260812 06:17:19.134938 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000018 (ops 85-89)
I20260812 06:17:19.134984 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000019 (ops 90-94)
I20260812 06:17:19.135028 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000020 (ops 95-99)
I20260812 06:17:19.135073 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000021 (ops 100-104)
I20260812 06:17:19.135118 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000022 (ops 105-109)
I20260812 06:17:19.135164 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000023 (ops 110-114)
I20260812 06:17:19.135210 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000024 (ops 115-119)
I20260812 06:17:19.135254 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000025 (ops 120-124)
I20260812 06:17:19.135299 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000026 (ops 125-129)
I20260812 06:17:19.168236 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: LogGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.034s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:17:19.168692 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=6.157687
I20260812 06:17:19.194478 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.026s	user 0.017s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10593,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:19.194913 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac): 483 bytes on disk
I20260812 06:17:19.195293 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.195839 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:19.406323 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.210s	user 0.128s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877223,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":477,"lbm_read_time_us":12425,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35878,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:19.407565 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=18.063937
I20260812 06:17:19.480335 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.073s	user 0.032s	sys 0.039s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27928,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.480962 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:19.491688 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.492115 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:19.691017 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.199s	user 0.130s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":972,"lbm_read_time_us":15746,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35430,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:19.691568 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:19.759239 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.067s	user 0.034s	sys 0.025s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":29858,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.759892 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:19.777009 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.777714 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:19.962574 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.185s	user 0.120s	sys 0.053s 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":977,"lbm_read_time_us":13454,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29277,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:17:19.963177 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:20.016157 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.053s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21998,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.016656 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:20.038337 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.021s	user 0.009s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.039075 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:20.230612 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.191s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":15081,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30945,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:17:20.231223 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:20.282049 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.051s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19408,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.282517 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:20.294917 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.295599 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:20.481114 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.185s	user 0.116s	sys 0.054s 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":1154,"lbm_read_time_us":11688,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30974,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:20.481828 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:20.529652 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.048s	user 0.024s	sys 0.017s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19382,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.530195 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:20.565460 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushMRSOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.035s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1275,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1626,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:20.566501 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac): 447 bytes on disk
I20260812 06:17:20.566941 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: UndoDeltaBlockGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.567554 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=3.181125
I20260812 06:17:20.580535 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4574,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.581039 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling LogGCOp(8525e652a3c54c169b9743dfb2d531ac): free 112239554 bytes of WAL
I20260812 06:17:20.581278 13366 log_reader.cc:385] T 8525e652a3c54c169b9743dfb2d531ac: removed 11 log segments from log reader
I20260812 06:17:20.581323 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000027 (ops 130-134)
I20260812 06:17:20.581353 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000028 (ops 135-139)
I20260812 06:17:20.581415 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000029 (ops 140-144)
I20260812 06:17:20.581459 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000030 (ops 145-149)
I20260812 06:17:20.581501 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000031 (ops 150-154)
I20260812 06:17:20.581568 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000032 (ops 155-158)
I20260812 06:17:20.581620 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000033 (ops 159-163)
I20260812 06:17:20.581671 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000034 (ops 164-168)
I20260812 06:17:20.581697 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000035 (ops 169-173)
I20260812 06:17:20.581736 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000036 (ops 174-178)
I20260812 06:17:20.581775 13366 log.cc:1079] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/8525e652a3c54c169b9743dfb2d531ac/wal-000000037 (ops 179-183)
I20260812 06:17:20.606559 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: LogGCOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.025s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:17:20.607077 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:20.630446 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.023s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.630983 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:20.647347 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.647866 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:20.894421 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.246s	user 0.126s	sys 0.117s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3281,"lbm_read_time_us":16774,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43786,"lbm_writes_lt_1ms":743,"mutex_wait_us":2512,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:17:20.895102 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=14.095187
I20260812 06:17:20.944765 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.945286 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac): perf score=2.188937
I20260812 06:17:20.959501 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: FlushDeltaMemStoresOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.960014 13479 maintenance_manager.cc:419] P 7d195897fe894ae994388de788d04489: Scheduling MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac): perf score=1.000000
I20260812 06:17:21.045985 13200 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.878s	user 1.741s	sys 0.167s
I20260812 06:17:21.107745 13200 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.005s	sys 0.000s
I20260812 06:17:21.108500 13200 tablet_server.cc:179] TabletServer@127.12.228.1:0 shutting down...
I20260812 06:17:21.120499 13366 maintenance_manager.cc:643] P 7d195897fe894ae994388de788d04489: MajorDeltaCompactionOp(8525e652a3c54c169b9743dfb2d531ac) complete. Timing: real 0.160s	user 0.092s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":631,"lbm_read_time_us":12425,"lbm_reads_lt_1ms":560,"lbm_write_time_us":29047,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:17:21.121183 13200 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:21.121595 13200 tablet_replica.cc:333] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489: stopping tablet replica
I20260812 06:17:21.121834 13200 raft_consensus.cc:2243] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.122063 13200 raft_consensus.cc:2272] T 8525e652a3c54c169b9743dfb2d531ac P 7d195897fe894ae994388de788d04489 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.138999 13200 tablet_server.cc:196] TabletServer@127.12.228.1:0 shutdown complete.
I20260812 06:17:21.167240 13200 master.cc:562] Master@127.12.228.62:45473 shutting down...
I20260812 06:17:21.171680 13200 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.171895 13200 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.171983 13200 tablet_replica.cc:333] T 00000000000000000000000000000000 P f006c4a4ab6549fbabfa416393330cee: stopping tablet replica
I20260812 06:17:21.184384 13200 master.cc:584] Master@127.12.228.62:45473 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5406 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:21.293114 13200 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.228.62:33087
I20260812 06:17:21.293560 13200 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:21.295981 13530 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:17:21.296051 13533 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:17:21.296135 13529 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:17:21.296155 13200 server_base.cc:1061] running on GCE node
I20260812 06:17:21.296413 13200 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:21.296453 13200 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:17:21.296468 13200 hybrid_clock.cc:648] HybridClock initialized: now 1786515441296469 us; error 0 us; skew 500 ppm
I20260812 06:17:21.297300 13200 webserver.cc:533] Webserver started at http://127.12.228.62:42635/ using document root <none> and password file <none>
I20260812 06:17:21.297488 13200 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:21.297556 13200 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:21.297637 13200 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:21.298034 13200 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/master-0-root/instance:
uuid: "58b3fb3be4764741b7e460d8f26a1124"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-x4qh"
I20260812 06:17:21.299662 13200 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:21.300598 13540 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:17:21.301007 13200 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:21.301096 13200 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/master-0-root
uuid: "58b3fb3be4764741b7e460d8f26a1124"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-x4qh"
I20260812 06:17:21.301179 13200 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-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:17:21.314553 13200 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:21.314942 13200 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:21.319340 13200 rpc_server.cc:307] RPC server started. Bound to: 127.12.228.62:33087
I20260812 06:17:21.320287 13635 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.228.62:33087 every 8 connection(s)
I20260812 06:17:21.322134 13636 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:17:21.325290 13636 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124: Bootstrap starting.
I20260812 06:17:21.326092 13636 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:21.327132 13636 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124: No bootstrap required, opened a new log
I20260812 06:17:21.327575 13636 raft_consensus.cc:359] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER }
I20260812 06:17:21.327662 13636 raft_consensus.cc:385] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:21.327721 13636 raft_consensus.cc:740] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 58b3fb3be4764741b7e460d8f26a1124, State: Initialized, Role: FOLLOWER
I20260812 06:17:21.327924 13636 consensus_queue.cc:260] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [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: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER }
I20260812 06:17:21.328024 13636 raft_consensus.cc:399] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:21.328104 13636 raft_consensus.cc:493] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:21.328166 13636 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:21.328855 13636 raft_consensus.cc:515] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER }
I20260812 06:17:21.329011 13636 leader_election.cc:304] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [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: 58b3fb3be4764741b7e460d8f26a1124; no voters: 
I20260812 06:17:21.329221 13636 leader_election.cc:290] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:21.329313 13640 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:21.329571 13640 raft_consensus.cc:697] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 1 LEADER]: Becoming Leader. State: Replica: 58b3fb3be4764741b7e460d8f26a1124, State: Running, Role: LEADER
I20260812 06:17:21.329708 13640 consensus_queue.cc:237] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [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: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER }
I20260812 06:17:21.329711 13636 sys_catalog.cc:565] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:21.330195 13645 sys_catalog.cc:455] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 58b3fb3be4764741b7e460d8f26a1124. Latest consensus state: current_term: 1 leader_uuid: "58b3fb3be4764741b7e460d8f26a1124" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER } }
I20260812 06:17:21.330178 13641 sys_catalog.cc:455] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "58b3fb3be4764741b7e460d8f26a1124" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58b3fb3be4764741b7e460d8f26a1124" member_type: VOTER } }
I20260812 06:17:21.330327 13645 sys_catalog.cc:458] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:21.330401 13641 sys_catalog.cc:458] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:21.330960 13651 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:21.331763 13651 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:21.332018 13200 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:21.333639 13651 catalog_manager.cc:1383] Generated new cluster ID: a4770fe341d64de9a595542c45842e6d
I20260812 06:17:21.333710 13651 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:21.378504 13651 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:21.379112 13651 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:21.382865 13651 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124: Generated new TSK 0
I20260812 06:17:21.383040 13651 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:21.396580 13200 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:21.398638 13673 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:17:21.398682 13672 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:17:21.398710 13682 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:17:21.398950 13200 server_base.cc:1061] running on GCE node
I20260812 06:17:21.399103 13200 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:21.399142 13200 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:17:21.399158 13200 hybrid_clock.cc:648] HybridClock initialized: now 1786515441399158 us; error 0 us; skew 500 ppm
I20260812 06:17:21.400028 13200 webserver.cc:533] Webserver started at http://127.12.228.1:39347/ using document root <none> and password file <none>
I20260812 06:17:21.400166 13200 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:21.400211 13200 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:21.400262 13200 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:21.400624 13200 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/instance:
uuid: "3e67b21a542146a5a21ce93acdf6af05"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-x4qh"
I20260812 06:17:21.402146 13200 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:21.403420 13691 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:17:21.403702 13200 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:21.403782 13200 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root
uuid: "3e67b21a542146a5a21ce93acdf6af05"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-x4qh"
I20260812 06:17:21.403861 13200 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-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:17:21.419024 13200 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:21.419497 13200 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:21.419785 13200 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:21.420254 13200 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:21.420316 13200 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:21.420380 13200 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:21.420426 13200 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:21.424880 13200 rpc_server.cc:307] RPC server started. Bound to: 127.12.228.1:42697
I20260812 06:17:21.425506 13794 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.228.1:42697 every 8 connection(s)
I20260812 06:17:21.433772 13795 heartbeater.cc:344] Connected to a master server at 127.12.228.62:33087
I20260812 06:17:21.433908 13795 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:21.434163 13795 heartbeater.cc:507] Master 127.12.228.62:33087 requested a full tablet report, sending...
I20260812 06:17:21.434840 13576 ts_manager.cc:194] Registered new tserver with Master: 3e67b21a542146a5a21ce93acdf6af05 (127.12.228.1:42697)
I20260812 06:17:21.435567 13200 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009982385s
I20260812 06:17:21.435644 13576 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39714
I20260812 06:17:21.442698 13576 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39728:
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:17:21.451474 13733 tablet_service.cc:1511] Processing CreateTablet for tablet f4ec2dc9bae547af9933b7d800449bf3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f1d76f0dc9a74c6d8994398556afce83]), partition=
I20260812 06:17:21.451790 13733 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f4ec2dc9bae547af9933b7d800449bf3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:21.453915 13823 tablet_bootstrap.cc:492] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Bootstrap starting.
I20260812 06:17:21.454795 13823 tablet_bootstrap.cc:654] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:21.455942 13823 tablet_bootstrap.cc:492] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: No bootstrap required, opened a new log
I20260812 06:17:21.456054 13823 ts_tablet_manager.cc:1403] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:21.456583 13823 raft_consensus.cc:359] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e67b21a542146a5a21ce93acdf6af05" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 42697 } }
I20260812 06:17:21.456700 13823 raft_consensus.cc:385] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:21.456754 13823 raft_consensus.cc:740] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3e67b21a542146a5a21ce93acdf6af05, State: Initialized, Role: FOLLOWER
I20260812 06:17:21.456898 13823 consensus_queue.cc:260] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [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: "3e67b21a542146a5a21ce93acdf6af05" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 42697 } }
I20260812 06:17:21.457021 13823 raft_consensus.cc:399] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:21.457067 13823 raft_consensus.cc:493] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:21.457122 13823 raft_consensus.cc:3060] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:21.457829 13823 raft_consensus.cc:515] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e67b21a542146a5a21ce93acdf6af05" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 42697 } }
I20260812 06:17:21.457993 13823 leader_election.cc:304] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [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: 3e67b21a542146a5a21ce93acdf6af05; no voters: 
I20260812 06:17:21.458264 13823 leader_election.cc:290] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:21.458415 13827 raft_consensus.cc:2804] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:21.458643 13795 heartbeater.cc:499] Master 127.12.228.62:33087 was elected leader, sending a full tablet report...
I20260812 06:17:21.458657 13827 raft_consensus.cc:697] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 1 LEADER]: Becoming Leader. State: Replica: 3e67b21a542146a5a21ce93acdf6af05, State: Running, Role: LEADER
I20260812 06:17:21.458868 13827 consensus_queue.cc:237] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [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: "3e67b21a542146a5a21ce93acdf6af05" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 42697 } }
I20260812 06:17:21.458913 13823 ts_tablet_manager.cc:1434] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:21.460230 13576 catalog_manager.cc:5719] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3e67b21a542146a5a21ce93acdf6af05 (127.12.228.1). New cstate: current_term: 1 leader_uuid: "3e67b21a542146a5a21ce93acdf6af05" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e67b21a542146a5a21ce93acdf6af05" member_type: VOTER last_known_addr { host: "127.12.228.1" port: 42697 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:21.522861 13200 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.018s	sys 0.004s
I20260812 06:17:21.676016 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=19.054940
I20260812 06:17:21.835801 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.160s	user 0.126s	sys 0.033s Metrics: {"bytes_written":13374123,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":930,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39809,"lbm_writes_lt_1ms":783,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1630}
I20260812 06:17:21.836467 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling LogGCOp(f4ec2dc9bae547af9933b7d800449bf3): free 20743831 bytes of WAL
I20260812 06:17:21.836714 13698 log_reader.cc:385] T f4ec2dc9bae547af9933b7d800449bf3: removed 2 log segments from log reader
I20260812 06:17:21.836782 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000001 (ops 1-6)
I20260812 06:17:21.836848 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000002 (ops 7-11)
I20260812 06:17:21.841169 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: LogGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.005s	user 0.003s	sys 0.000s Metrics: {}
I20260812 06:17:21.841516 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=3.181125
I20260812 06:17:21.855513 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4594951,"delete_count":0,"lbm_write_time_us":5416,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:17:21.856006 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3): 16411392 bytes on disk
I20260812 06:17:21.856499 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3) 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:17:21.856926 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.196750
I20260812 06:17:21.867871 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:17:21.868718 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:22.051656 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.183s	user 0.112s	sys 0.070s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774778,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1017,"lbm_read_time_us":13277,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30237,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":392,"threads_started":5,"update_count":2500}
I20260812 06:17:22.052373 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:22.124339 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.072s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":31057,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.124980 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:22.136086 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s 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:17:22.136576 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:22.313481 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.177s	user 0.131s	sys 0.043s 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":216,"lbm_read_time_us":12172,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31034,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:22.314085 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:22.376094 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.062s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23100,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:22.376598 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:22.387269 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4336,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.387831 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:22.570587 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.183s	user 0.119s	sys 0.056s 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":246,"lbm_read_time_us":13301,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31041,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:17:22.571099 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:22.636438 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.065s	user 0.046s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21134,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.636973 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:22.647544 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.648000 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:22.834823 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.187s	user 0.132s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":607,"lbm_read_time_us":12490,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29664,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:17:22.835466 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:22.900699 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.065s	user 0.020s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.901244 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:22.912492 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.913067 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:23.095599 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.182s	user 0.114s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":12852,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31765,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:23.096233 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=11.118625
I20260812 06:17:23.125945 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.030s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13280,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:23.126426 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:23.139668 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4896,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:23.140275 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:23.170348 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1511,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1467,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:23.171015 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling LogGCOp(f4ec2dc9bae547af9933b7d800449bf3): free 120553442 bytes of WAL
I20260812 06:17:23.171312 13698 log_reader.cc:385] T f4ec2dc9bae547af9933b7d800449bf3: removed 12 log segments from log reader
I20260812 06:17:23.171411 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000003 (ops 12-16)
I20260812 06:17:23.171468 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000004 (ops 17-21)
I20260812 06:17:23.171530 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000005 (ops 22-26)
I20260812 06:17:23.171569 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000006 (ops 27-31)
I20260812 06:17:23.171605 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000007 (ops 32-36)
I20260812 06:17:23.171643 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000008 (ops 37-40)
I20260812 06:17:23.171681 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000009 (ops 41-45)
I20260812 06:17:23.171710 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000010 (ops 46-50)
I20260812 06:17:23.171749 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000011 (ops 51-54)
I20260812 06:17:23.171784 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000012 (ops 55-59)
I20260812 06:17:23.171823 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000013 (ops 60-64)
I20260812 06:17:23.171859 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000014 (ops 65-69)
I20260812 06:17:23.199889 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: LogGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.029s	user 0.002s	sys 0.026s Metrics: {}
I20260812 06:17:23.200409 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3): 462 bytes on disk
I20260812 06:17:23.200865 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:23.201413 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=3.181125
I20260812 06:17:23.219518 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.018s	user 0.005s	sys 0.011s Metrics: {"bytes_written":5005193,"delete_count":0,"lbm_write_time_us":6738,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:17:23.220019 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:23.232759 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4615,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:23.233239 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:23.439546 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.206s	user 0.150s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1039,"lbm_read_time_us":15253,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34160,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":130,"threads_started":1,"update_count":3000}
I20260812 06:17:23.440150 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:23.502259 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.062s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.502758 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:23.517356 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.518106 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:23.692386 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.174s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1849,"lbm_read_time_us":12763,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28079,"lbm_writes_lt_1ms":543,"mutex_wait_us":549,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:23.692997 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:23.753763 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.061s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.754437 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:23.765684 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.766189 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:23.946205 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.180s	user 0.114s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":13931,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29153,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:17:23.946990 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:24.003556 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.056s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27615,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.004073 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.016036 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.016505 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:24.186226 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.170s	user 0.108s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":10541,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28670,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:17:24.187188 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:24.239928 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.052s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23950,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.240432 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.261788 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.262331 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.283277 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.021s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.283980 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:24.482112 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.198s	user 0.129s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":359,"lbm_read_time_us":14884,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32902,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":3000}
I20260812 06:17:24.482745 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:24.537869 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.055s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19785,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.538443 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.549348 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.549779 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:24.577962 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":311,"dirs.run_wall_time_us":1400,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1389,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:24.578608 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling LogGCOp(f4ec2dc9bae547af9933b7d800449bf3): free 112239324 bytes of WAL
I20260812 06:17:24.578850 13698 log_reader.cc:385] T f4ec2dc9bae547af9933b7d800449bf3: removed 11 log segments from log reader
I20260812 06:17:24.578895 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000015 (ops 70-74)
I20260812 06:17:24.578925 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000016 (ops 75-78)
I20260812 06:17:24.578992 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000017 (ops 79-83)
I20260812 06:17:24.579043 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000018 (ops 84-88)
I20260812 06:17:24.579085 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000019 (ops 89-93)
I20260812 06:17:24.579121 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000020 (ops 94-98)
I20260812 06:17:24.579171 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000021 (ops 99-103)
I20260812 06:17:24.579209 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000022 (ops 104-108)
I20260812 06:17:24.579247 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000023 (ops 109-113)
I20260812 06:17:24.579285 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000024 (ops 114-118)
I20260812 06:17:24.579322 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000025 (ops 119-123)
I20260812 06:17:24.608479 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: LogGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:17:24.608933 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.619552 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.619972 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3): 448 bytes on disk
I20260812 06:17:24.620380 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:24.620859 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:24.823683 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.203s	user 0.134s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":792,"lbm_read_time_us":15021,"lbm_reads_lt_1ms":669,"lbm_write_time_us":33642,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7168,"thread_start_us":119,"threads_started":1,"update_count":3000}
I20260812 06:17:24.824545 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:24.881171 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.056s	user 0.021s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25363,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.881876 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:24.898602 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.899070 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:25.066443 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.167s	user 0.107s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":11774,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28594,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:17:25.067155 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:25.129840 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.062s	user 0.021s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22146,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.130620 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:25.149318 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.149927 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:25.331175 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.181s	user 0.130s	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":152,"lbm_read_time_us":12297,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31639,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:25.331926 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:25.381924 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.050s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.382507 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:25.405668 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.023s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.406447 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:25.579569 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.173s	user 0.118s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1190,"lbm_read_time_us":12417,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29846,"lbm_writes_lt_1ms":543,"mutex_wait_us":641,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2500}
I20260812 06:17:25.580482 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:25.636675 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.056s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.637225 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:25.647883 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.648433 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:25.818607 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.170s	user 0.126s	sys 0.036s 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":2246,"lbm_read_time_us":10566,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30880,"lbm_writes_lt_1ms":543,"mutex_wait_us":373,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:17:25.819424 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=11.118625
I20260812 06:17:25.849367 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.029s	user 0.022s	sys 0.006s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13281,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:25.850004 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:25.868098 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.018s	user 0.001s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5100,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:25.868681 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:26.009138 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.140s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":707,"lbm_read_time_us":9097,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27465,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:17:26.009960 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=10.126437
I20260812 06:17:26.055521 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.045s	user 0.035s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17016,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.056058 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:26.067598 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.068123 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:26.097776 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushMRSOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1457,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1653,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:26.098431 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling LogGCOp(f4ec2dc9bae547af9933b7d800449bf3): free 120553614 bytes of WAL
I20260812 06:17:26.098664 13698 log_reader.cc:385] T f4ec2dc9bae547af9933b7d800449bf3: removed 12 log segments from log reader
I20260812 06:17:26.098712 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000026 (ops 124-128)
I20260812 06:17:26.098742 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000027 (ops 129-133)
I20260812 06:17:26.098809 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000028 (ops 134-138)
I20260812 06:17:26.098852 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000029 (ops 139-142)
I20260812 06:17:26.098894 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000030 (ops 143-147)
I20260812 06:17:26.098960 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000031 (ops 148-152)
I20260812 06:17:26.098999 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000032 (ops 153-157)
I20260812 06:17:26.099038 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000033 (ops 158-162)
I20260812 06:17:26.099079 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000034 (ops 163-166)
I20260812 06:17:26.099118 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000035 (ops 167-171)
I20260812 06:17:26.099159 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000036 (ops 172-176)
I20260812 06:17:26.099210 13698 log.cc:1079] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: Deleting log segment in path: /tmp/dist-test-taskLdCpGS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435862399-13200-0/minicluster-data/ts-0-root/wals/f4ec2dc9bae547af9933b7d800449bf3/wal-000000037 (ops 177-181)
I20260812 06:17:26.128037 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: LogGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:26.128475 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=4.173312
I20260812 06:17:26.145484 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.017s	user 0.004s	sys 0.010s Metrics: {"bytes_written":5948752,"delete_count":0,"lbm_write_time_us":7021,"lbm_writes_lt_1ms":148,"reinsert_count":0,"update_count":725}
I20260812 06:17:26.145977 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3): 462 bytes on disk
I20260812 06:17:26.146420 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: UndoDeltaBlockGCOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.146967 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.196750
I20260812 06:17:26.161194 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.014s	user 0.003s	sys 0.007s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":4030,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:17:26.161697 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:26.330471 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.169s	user 0.113s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877295,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4900,"lbm_read_time_us":12064,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34596,"lbm_writes_lt_1ms":643,"mutex_wait_us":1088,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":178,"threads_started":1,"update_count":3000}
I20260812 06:17:26.331427 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=14.095187
I20260812 06:17:26.391943 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.060s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29645,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.392421 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:26.409803 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.410281 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=2.188937
I20260812 06:17:26.423854 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.425940 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=1.000000
I20260812 06:17:26.500042 13200 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.977s	user 1.847s	sys 0.193s
I20260812 06:17:26.599570 13200 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.004s	sys 0.000s
I20260812 06:17:26.600067 13200 tablet_server.cc:179] TabletServer@127.12.228.1:0 shutting down...
I20260812 06:17:26.602291 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: MajorDeltaCompactionOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.175s	user 0.128s	sys 0.046s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":430,"lbm_read_time_us":12925,"lbm_reads_lt_1ms":669,"lbm_write_time_us":38812,"lbm_writes_lt_1ms":643,"mutex_wait_us":143,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:17:26.602965 13797 maintenance_manager.cc:419] P 3e67b21a542146a5a21ce93acdf6af05: Scheduling FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3): perf score=6.157687
I20260812 06:17:26.625103 13698 maintenance_manager.cc:643] P 3e67b21a542146a5a21ce93acdf6af05: FlushDeltaMemStoresOp(f4ec2dc9bae547af9933b7d800449bf3) complete. Timing: real 0.022s	user 0.012s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9461,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:26.625631 13200 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:26.625842 13200 tablet_replica.cc:333] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05: stopping tablet replica
I20260812 06:17:26.625974 13200 raft_consensus.cc:2243] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.626111 13200 raft_consensus.cc:2272] T f4ec2dc9bae547af9933b7d800449bf3 P 3e67b21a542146a5a21ce93acdf6af05 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.639880 13200 tablet_server.cc:196] TabletServer@127.12.228.1:0 shutdown complete.
I20260812 06:17:26.654621 13200 master.cc:562] Master@127.12.228.62:33087 shutting down...
I20260812 06:17:26.658070 13200 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.658280 13200 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.658370 13200 tablet_replica.cc:333] T 00000000000000000000000000000000 P 58b3fb3be4764741b7e460d8f26a1124: stopping tablet replica
I20260812 06:17:26.670744 13200 master.cc:584] Master@127.12.228.62:33087 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5484 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10892 ms total)

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