[==========] 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:19:12.609480   579 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.144.254:37453
I20260812 06:19:12.610419   579 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:19:12.610996   579 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:12.617107   579 server_base.cc:1061] running on GCE node
W20260812 06:19:12.617194   592 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.617329   588 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.617352   587 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.617815   579 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.617903   579 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.617933   579 hybrid_clock.cc:648] HybridClock initialized: now 1786515552617930 us; error 0 us; skew 500 ppm
I20260812 06:19:12.619550   579 webserver.cc:533] Webserver started at http://127.0.144.254:34547/ using document root <none> and password file <none>
I20260812 06:19:12.620014   579 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.620066   579 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.620251   579 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.621727   579 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/master-0-root/instance:
uuid: "5461e69685464bc788d6d08d31a1b3f2"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-1vmg"
I20260812 06:19:12.624817   579 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:19:12.626588   601 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.627501   579 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:12.627591   579 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/master-0-root
uuid: "5461e69685464bc788d6d08d31a1b3f2"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-1vmg"
I20260812 06:19:12.627676   579 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:12.644757   579 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:12.645335   579 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:19:12.645460   579 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:12.653185   690 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.144.254:37453 every 8 connection(s)
I20260812 06:19:12.653195   579 rpc_server.cc:307] RPC server started. Bound to: 127.0.144.254:37453
I20260812 06:19:12.655400   691 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:12.660593   691 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: Bootstrap starting.
I20260812 06:19:12.662899   691 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:12.663784   691 log.cc:826] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:12.665342   691 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: No bootstrap required, opened a new log
I20260812 06:19:12.668112   691 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER }
I20260812 06:19:12.668289   691 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:12.668334   691 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5461e69685464bc788d6d08d31a1b3f2, State: Initialized, Role: FOLLOWER
I20260812 06:19:12.668968   691 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [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: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER }
I20260812 06:19:12.669114   691 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:12.669180   691 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:12.669309   691 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:12.670053   691 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER }
I20260812 06:19:12.670462   691 leader_election.cc:304] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [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: 5461e69685464bc788d6d08d31a1b3f2; no voters: 
I20260812 06:19:12.670761   691 leader_election.cc:290] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:12.670888   698 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:12.671124   698 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 1 LEADER]: Becoming Leader. State: Replica: 5461e69685464bc788d6d08d31a1b3f2, State: Running, Role: LEADER
I20260812 06:19:12.671540   698 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [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: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER }
I20260812 06:19:12.671761   691 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:12.673204   701 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5461e69685464bc788d6d08d31a1b3f2. Latest consensus state: current_term: 1 leader_uuid: "5461e69685464bc788d6d08d31a1b3f2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER } }
I20260812 06:19:12.673254   699 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5461e69685464bc788d6d08d31a1b3f2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5461e69685464bc788d6d08d31a1b3f2" member_type: VOTER } }
I20260812 06:19:12.673308   701 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.673364   699 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.673687   714 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:12.673988   579 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:12.675942   714 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:12.680274   714 catalog_manager.cc:1383] Generated new cluster ID: 401ed0425b0f4b579852412b37d0ae61
I20260812 06:19:12.680325   714 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:12.690327   714 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:12.691134   714 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:12.698275   714 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: Generated new TSK 0
I20260812 06:19:12.698853   714 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:12.706425   579 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:12.709002   733 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:19:12.709085   734 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.709182   579 server_base.cc:1061] running on GCE node
W20260812 06:19:12.709323   740 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:19:12.709666   579 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.709731   579 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.709753   579 hybrid_clock.cc:648] HybridClock initialized: now 1786515552709753 us; error 0 us; skew 500 ppm
I20260812 06:19:12.710637   579 webserver.cc:533] Webserver started at http://127.0.144.193:43389/ using document root <none> and password file <none>
I20260812 06:19:12.710808   579 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.710867   579 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.710963   579 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.711398   579 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/instance:
uuid: "429beeb9a51845a1962f3ee5a189f358"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-1vmg"
I20260812 06:19:12.713161   579 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:12.714255   746 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.714483   579 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:12.714557   579 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root
uuid: "429beeb9a51845a1962f3ee5a189f358"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-1vmg"
I20260812 06:19:12.714624   579 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:12.728374   579 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:12.729054   579 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:12.729578   579 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:12.730571   579 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:12.730683   579 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.730767   579 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:12.730816   579 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.737126   579 rpc_server.cc:307] RPC server started. Bound to: 127.0.144.193:35679
I20260812 06:19:12.737154   858 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.144.193:35679 every 8 connection(s)
I20260812 06:19:12.750795   859 heartbeater.cc:344] Connected to a master server at 127.0.144.254:37453
I20260812 06:19:12.751048   859 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:12.751514   859 heartbeater.cc:507] Master 127.0.144.254:37453 requested a full tablet report, sending...
I20260812 06:19:12.752918   627 ts_manager.cc:194] Registered new tserver with Master: 429beeb9a51845a1962f3ee5a189f358 (127.0.144.193:35679)
I20260812 06:19:12.753212   579 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015463424s
I20260812 06:19:12.754045   627 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55556
I20260812 06:19:12.762283   627 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55564:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:12.775914   800 tablet_service.cc:1511] Processing CreateTablet for tablet 536798d45eb542bbb0e4533986c6cf14 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ceab5929ceec4fbe84c74c3421cd22d0]), partition=
I20260812 06:19:12.776351   800 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 536798d45eb542bbb0e4533986c6cf14. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:12.779057   880 tablet_bootstrap.cc:492] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Bootstrap starting.
I20260812 06:19:12.780006   880 tablet_bootstrap.cc:654] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:12.780998   880 tablet_bootstrap.cc:492] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: No bootstrap required, opened a new log
I20260812 06:19:12.781090   880 ts_tablet_manager.cc:1403] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:12.781474   880 raft_consensus.cc:359] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "429beeb9a51845a1962f3ee5a189f358" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 35679 } }
I20260812 06:19:12.781569   880 raft_consensus.cc:385] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:12.781601   880 raft_consensus.cc:740] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 429beeb9a51845a1962f3ee5a189f358, State: Initialized, Role: FOLLOWER
I20260812 06:19:12.781733   880 consensus_queue.cc:260] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [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: "429beeb9a51845a1962f3ee5a189f358" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 35679 } }
I20260812 06:19:12.781807   880 raft_consensus.cc:399] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:12.781849   880 raft_consensus.cc:493] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:12.781896   880 raft_consensus.cc:3060] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:12.782521   880 raft_consensus.cc:515] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "429beeb9a51845a1962f3ee5a189f358" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 35679 } }
I20260812 06:19:12.782644   880 leader_election.cc:304] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [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: 429beeb9a51845a1962f3ee5a189f358; no voters: 
I20260812 06:19:12.782827   880 leader_election.cc:290] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:12.782956   883 raft_consensus.cc:2804] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:12.783144   883 raft_consensus.cc:697] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 1 LEADER]: Becoming Leader. State: Replica: 429beeb9a51845a1962f3ee5a189f358, State: Running, Role: LEADER
I20260812 06:19:12.783242   880 ts_tablet_manager.cc:1434] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:12.783330   883 consensus_queue.cc:237] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [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: "429beeb9a51845a1962f3ee5a189f358" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 35679 } }
I20260812 06:19:12.783663   859 heartbeater.cc:499] Master 127.0.144.254:37453 was elected leader, sending a full tablet report...
I20260812 06:19:12.785859   627 catalog_manager.cc:5719] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 reported cstate change: term changed from 0 to 1, leader changed from <none> to 429beeb9a51845a1962f3ee5a189f358 (127.0.144.193). New cstate: current_term: 1 leader_uuid: "429beeb9a51845a1962f3ee5a189f358" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "429beeb9a51845a1962f3ee5a189f358" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 35679 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:12.844774   579 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.013s	sys 0.012s
I20260812 06:19:12.988164   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushMRSOp(536798d45eb542bbb0e4533986c6cf14): perf score=19.054940
I20260812 06:19:13.145593   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushMRSOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.157s	user 0.117s	sys 0.036s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":242,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":992,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38893,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":5888,"thread_start_us":160,"threads_started":1,"update_count":1450}
I20260812 06:19:13.146727   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling LogGCOp(536798d45eb542bbb0e4533986c6cf14): free 20743880 bytes of WAL
I20260812 06:19:13.147038   752 log_reader.cc:385] T 536798d45eb542bbb0e4533986c6cf14: removed 2 log segments from log reader
I20260812 06:19:13.147101   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000001 (ops 1-6)
I20260812 06:19:13.147198   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000002 (ops 7-11)
I20260812 06:19:13.152061   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: LogGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:13.152431   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14): 16821652 bytes on disk
I20260812 06:19:13.152982   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.153400   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:13.169049   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":500}
I20260812 06:19:13.169531   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:13.297117   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.127s	user 0.086s	sys 0.039s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303031,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":39,"lbm_read_time_us":6946,"lbm_reads_lt_1ms":450,"lbm_write_time_us":20727,"lbm_writes_lt_1ms":433,"mutex_wait_us":28,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":263,"threads_started":5,"update_count":1950}
I20260812 06:19:13.297715   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=10.126437
I20260812 06:19:13.340494   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19312,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.340974   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:13.355675   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.356137   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:13.466871   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.111s	user 0.094s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":822,"lbm_read_time_us":7308,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23409,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.467454   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=10.126437
I20260812 06:19:13.510258   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.043s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19909,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.511061   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:13.526721   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.527199   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:13.646657   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.119s	user 0.091s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":7741,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22096,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.647150   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=11.118625
I20260812 06:19:13.683102   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.036s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12257,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.683563   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:13.695302   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.695793   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:13.843588   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.148s	user 0.102s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":9831,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25821,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:19:13.844106   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=11.118625
I20260812 06:19:13.876339   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13939,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.876955   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:13.892782   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.016s	user 0.000s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4517,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.893272   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.008078   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.115s	user 0.103s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1038,"lbm_read_time_us":6984,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22961,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.008584   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=11.118625
I20260812 06:19:14.043421   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.035s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14646,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.043890   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:14.053701   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3492,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.054298   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.172487   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.118s	user 0.082s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":129,"lbm_read_time_us":7091,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23941,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.173039   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=10.126437
I20260812 06:19:14.208870   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.036s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307504,"delete_count":0,"lbm_write_time_us":16083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.209347   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:14.220489   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.221071   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.349351   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.128s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713286,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":6811,"lbm_read_time_us":9355,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24793,"lbm_writes_lt_1ms":443,"mutex_wait_us":2916,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:19:14.349901   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=10.126437
I20260812 06:19:14.388252   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.038s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12907,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.388744   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:14.398481   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.398869   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushMRSOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.426697   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushMRSOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.028s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1442,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:14.427554   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.563346   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.136s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":10462,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22981,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.563957   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling LogGCOp(536798d45eb542bbb0e4533986c6cf14): free 125163351 bytes of WAL
I20260812 06:19:14.564261   752 log_reader.cc:385] T 536798d45eb542bbb0e4533986c6cf14: removed 12 log segments from log reader
I20260812 06:19:14.564347   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000003 (ops 12-16)
I20260812 06:19:14.564406   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000004 (ops 17-21)
I20260812 06:19:14.564438   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000005 (ops 22-26)
I20260812 06:19:14.564473   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000006 (ops 27-31)
I20260812 06:19:14.564519   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000007 (ops 32-36)
I20260812 06:19:14.564555   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000008 (ops 37-41)
I20260812 06:19:14.564587   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000009 (ops 42-46)
I20260812 06:19:14.564621   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000010 (ops 47-51)
I20260812 06:19:14.564656   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000011 (ops 52-56)
I20260812 06:19:14.564688   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000012 (ops 57-61)
I20260812 06:19:14.564720   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000013 (ops 62-67)
I20260812 06:19:14.564754   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000014 (ops 68-72)
I20260812 06:19:14.589026   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: LogGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:14.589593   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14): 483 bytes on disk
I20260812 06:19:14.590139   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.590739   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:14.635758   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.045s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18877,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.636505   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:14.649272   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.649658   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:14.793619   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.144s	user 0.106s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":10129,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27886,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:19:14.794245   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:14.842038   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.048s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21802,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.842499   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:14.858523   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.859030   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:15.001904   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.141s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":8598,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29216,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:19:15.002417   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:15.048662   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.046s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20341,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.049199   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.059584   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.059998   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:15.207604   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.147s	user 0.128s	sys 0.012s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":11209,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28057,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:19:15.208165   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:15.252772   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.044s	user 0.039s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.253244   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.263226   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.263810   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:15.415634   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.152s	user 0.111s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":969,"lbm_read_time_us":9679,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31258,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:19:15.416131   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=12.110812
I20260812 06:19:15.467859   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.052s	user 0.034s	sys 0.013s Metrics: {"bytes_written":13620268,"delete_count":0,"lbm_write_time_us":20594,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1660}
I20260812 06:19:15.468304   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.479211   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.011s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":2905,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:15.479615   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.488282   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3203,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.488674   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:15.671077   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.182s	user 0.105s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815777,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1313,"lbm_read_time_us":11312,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33526,"lbm_writes_lt_1ms":543,"mutex_wait_us":661,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:19:15.671663   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:15.727321   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.055s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18756,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.727903   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.737782   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.738288   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushMRSOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:15.767820   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushMRSOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:15.768554   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling LogGCOp(536798d45eb542bbb0e4533986c6cf14): free 124710322 bytes of WAL
I20260812 06:19:15.768782   752 log_reader.cc:385] T 536798d45eb542bbb0e4533986c6cf14: removed 12 log segments from log reader
I20260812 06:19:15.768852   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000015 (ops 73-77)
I20260812 06:19:15.768895   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000016 (ops 78-82)
I20260812 06:19:15.768929   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000017 (ops 83-87)
I20260812 06:19:15.768958   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000018 (ops 88-92)
I20260812 06:19:15.768986   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000019 (ops 93-97)
I20260812 06:19:15.769017   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000020 (ops 98-102)
I20260812 06:19:15.769049   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000021 (ops 103-107)
I20260812 06:19:15.769079   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000022 (ops 108-112)
I20260812 06:19:15.769107   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000023 (ops 113-117)
I20260812 06:19:15.769134   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000024 (ops 118-122)
I20260812 06:19:15.769165   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000025 (ops 123-127)
I20260812 06:19:15.769197   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000026 (ops 128-132)
I20260812 06:19:15.795987   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: LogGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:15.796404   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14): 472 bytes on disk
I20260812 06:19:15.796829   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.797399   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=3.181125
I20260812 06:19:15.808564   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:15.808960   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:15.821964   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.822407   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:16.024544   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.202s	user 0.124s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":708,"lbm_read_time_us":14632,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33760,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:16.025094   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=18.063937
I20260812 06:19:16.092214   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.066s	user 0.029s	sys 0.035s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29365,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:16.092721   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:16.110433   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.110854   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:16.266341   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.155s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":10829,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31848,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":3000}
I20260812 06:19:16.266952   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:16.310678   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.043s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":18499,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.311262   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:16.331204   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.331761   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:16.471024   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.139s	user 0.108s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":8515,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25696,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:19:16.471580   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:16.518311   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.047s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20058,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.518719   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:16.657694   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.139s	user 0.087s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":896,"lbm_read_time_us":9010,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23142,"lbm_writes_lt_1ms":443,"mutex_wait_us":274,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:16.658211   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:16.704810   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.046s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.705346   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:16.715338   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.715906   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:16.891990   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.176s	user 0.118s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":11218,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27977,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:16.892549   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=14.095187
I20260812 06:19:16.934319   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.042s	user 0.032s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17350,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.934870   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:16.949848   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.950353   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:17.093498   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.143s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":793,"lbm_read_time_us":9503,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27538,"lbm_writes_lt_1ms":543,"mutex_wait_us":611,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:19:17.094211   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=11.118625
I20260812 06:19:17.144806   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.050s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16491,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.145385   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=6.157687
I20260812 06:19:17.169378   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.024s	user 0.011s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8969,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:17.169870   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushMRSOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:17.208384   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushMRSOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.038s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1319,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2548,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:17.209185   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14): 507 bytes on disk
I20260812 06:19:17.209684   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: UndoDeltaBlockGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.210227   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=3.181125
I20260812 06:19:17.219863   579 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.375s	user 1.682s	sys 0.088s
I20260812 06:19:17.229522   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:17.229920   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling LogGCOp(536798d45eb542bbb0e4533986c6cf14): free 145042543 bytes of WAL
I20260812 06:19:17.230124   752 log_reader.cc:385] T 536798d45eb542bbb0e4533986c6cf14: removed 14 log segments from log reader
I20260812 06:19:17.230166   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000027 (ops 133-137)
I20260812 06:19:17.230196   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000028 (ops 138-142)
I20260812 06:19:17.230240   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000029 (ops 143-147)
I20260812 06:19:17.230274   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000030 (ops 148-152)
I20260812 06:19:17.230305   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000031 (ops 153-157)
I20260812 06:19:17.230336   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000032 (ops 158-162)
I20260812 06:19:17.230366   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000033 (ops 163-167)
I20260812 06:19:17.230399   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000034 (ops 168-172)
I20260812 06:19:17.230429   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000035 (ops 173-176)
I20260812 06:19:17.230459   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000036 (ops 177-181)
I20260812 06:19:17.230489   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000037 (ops 182-186)
I20260812 06:19:17.230520   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000038 (ops 187-191)
I20260812 06:19:17.230551   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000039 (ops 192-196)
I20260812 06:19:17.230581   752 log.cc:1079] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552598986-579-0/minicluster-data/ts-0-root/wals/536798d45eb542bbb0e4533986c6cf14/wal-000000040 (ops 197-201)
I20260812 06:19:17.254385   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: LogGCOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:17.254729   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14): perf score=2.188937
I20260812 06:19:17.268280   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: FlushDeltaMemStoresOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5338,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.268635   860 maintenance_manager.cc:419] P 429beeb9a51845a1962f3ee5a189f358: Scheduling MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14): perf score=1.000000
I20260812 06:19:17.341435   579 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.121s	user 0.001s	sys 0.000s
I20260812 06:19:17.342031   579 tablet_server.cc:179] TabletServer@127.0.144.193:0 shutting down...
I20260812 06:19:17.436651   752 maintenance_manager.cc:643] P 429beeb9a51845a1962f3ee5a189f358: MajorDeltaCompactionOp(536798d45eb542bbb0e4533986c6cf14) complete. Timing: real 0.168s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_hit":584,"cfile_cache_hit_bytes":23835756,"cfile_cache_miss":150,"cfile_cache_miss_bytes":9184981,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":966,"lbm_read_time_us":5946,"lbm_reads_lt_1ms":182,"lbm_write_time_us":31493,"lbm_writes_lt_1ms":743,"mutex_wait_us":30,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:17.437291   579 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:17.437674   579 tablet_replica.cc:333] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358: stopping tablet replica
I20260812 06:19:17.437966   579 raft_consensus.cc:2243] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.438215   579 raft_consensus.cc:2272] T 536798d45eb542bbb0e4533986c6cf14 P 429beeb9a51845a1962f3ee5a189f358 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.453524   579 tablet_server.cc:196] TabletServer@127.0.144.193:0 shutdown complete.
I20260812 06:19:17.494310   579 master.cc:562] Master@127.0.144.254:37453 shutting down...
I20260812 06:19:17.497567   579 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.497738   579 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.497812   579 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5461e69685464bc788d6d08d31a1b3f2: stopping tablet replica
I20260812 06:19:17.509991   579 master.cc:584] Master@127.0.144.254:37453 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4976 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:17.596328   579 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.144.254:38139
I20260812 06:19:17.596738   579 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:17.598654   910 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:19:17.598670   916 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:17.598780   911 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:17.598742   579 server_base.cc:1061] running on GCE node
I20260812 06:19:17.599095   579 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:17.599138   579 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:17.599170   579 hybrid_clock.cc:648] HybridClock initialized: now 1786515557599170 us; error 0 us; skew 500 ppm
I20260812 06:19:17.599977   579 webserver.cc:533] Webserver started at http://127.0.144.254:36247/ using document root <none> and password file <none>
I20260812 06:19:17.600132   579 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:17.600183   579 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:17.600272   579 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:17.600636   579 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/master-0-root/instance:
uuid: "266180cd2d6143bfbf7e0777612b8126"
format_stamp: "Formatted at 2026-08-12 06:19:17 on dist-test-slave-1vmg"
I20260812 06:19:17.602069   579 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:17.603492   924 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:17.603713   579 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:17.603782   579 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/master-0-root
uuid: "266180cd2d6143bfbf7e0777612b8126"
format_stamp: "Formatted at 2026-08-12 06:19:17 on dist-test-slave-1vmg"
I20260812 06:19:17.603849   579 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:17.628252   579 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:17.628655   579 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:17.632771   579 rpc_server.cc:307] RPC server started. Bound to: 127.0.144.254:38139
I20260812 06:19:17.636596  1015 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.144.254:38139 every 8 connection(s)
I20260812 06:19:17.637035  1016 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:17.638942  1016 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126: Bootstrap starting.
I20260812 06:19:17.639757  1016 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:17.640661  1016 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126: No bootstrap required, opened a new log
I20260812 06:19:17.640998  1016 raft_consensus.cc:359] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER }
I20260812 06:19:17.641098  1016 raft_consensus.cc:385] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:17.641125  1016 raft_consensus.cc:740] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 266180cd2d6143bfbf7e0777612b8126, State: Initialized, Role: FOLLOWER
I20260812 06:19:17.641227  1016 consensus_queue.cc:260] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [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: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER }
I20260812 06:19:17.641279  1016 raft_consensus.cc:399] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:17.641306  1016 raft_consensus.cc:493] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:17.641337  1016 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:17.641937  1016 raft_consensus.cc:515] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER }
I20260812 06:19:17.642050  1016 leader_election.cc:304] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [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: 266180cd2d6143bfbf7e0777612b8126; no voters: 
I20260812 06:19:17.642191  1016 leader_election.cc:290] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:17.642298  1022 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:17.642479  1022 raft_consensus.cc:697] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 1 LEADER]: Becoming Leader. State: Replica: 266180cd2d6143bfbf7e0777612b8126, State: Running, Role: LEADER
I20260812 06:19:17.642612  1022 consensus_queue.cc:237] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [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: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER }
I20260812 06:19:17.642649  1016 sys_catalog.cc:565] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:17.643026  1023 sys_catalog.cc:455] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "266180cd2d6143bfbf7e0777612b8126" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER } }
I20260812 06:19:17.643164  1023 sys_catalog.cc:458] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:17.643043  1024 sys_catalog.cc:455] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 266180cd2d6143bfbf7e0777612b8126. Latest consensus state: current_term: 1 leader_uuid: "266180cd2d6143bfbf7e0777612b8126" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "266180cd2d6143bfbf7e0777612b8126" member_type: VOTER } }
I20260812 06:19:17.643417  1024 sys_catalog.cc:458] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:17.643806  1032 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:17.644445  1032 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:17.644596   579 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:17.646746  1032 catalog_manager.cc:1383] Generated new cluster ID: 244274f73ab74e61942243638c89d08b
I20260812 06:19:17.646857  1032 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:17.668100  1032 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:17.668639  1032 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:17.673346  1032 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126: Generated new TSK 0
I20260812 06:19:17.673487  1032 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:17.679772   579 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:17.681619  1051 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:19:17.681761  1054 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:17.681804  1056 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:19:17.681999   579 server_base.cc:1061] running on GCE node
I20260812 06:19:17.682140   579 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:17.682171   579 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:17.682185   579 hybrid_clock.cc:648] HybridClock initialized: now 1786515557682185 us; error 0 us; skew 500 ppm
I20260812 06:19:17.682955   579 webserver.cc:533] Webserver started at http://127.0.144.193:42997/ using document root <none> and password file <none>
I20260812 06:19:17.683092   579 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:17.683131   579 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:17.683185   579 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:17.683511   579 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/instance:
uuid: "51be7ae83c8e49879e8e9d13475ce935"
format_stamp: "Formatted at 2026-08-12 06:19:17 on dist-test-slave-1vmg"
I20260812 06:19:17.684846   579 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:17.685652  1065 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:17.685860   579 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:17.685922   579 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root
uuid: "51be7ae83c8e49879e8e9d13475ce935"
format_stamp: "Formatted at 2026-08-12 06:19:17 on dist-test-slave-1vmg"
I20260812 06:19:17.685978   579 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:17.698546   579 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:17.698861   579 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:17.699147   579 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:17.699601   579 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:17.699638   579 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:17.699673   579 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:17.699700   579 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:17.703768   579 rpc_server.cc:307] RPC server started. Bound to: 127.0.144.193:43399
I20260812 06:19:17.703811  1159 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.144.193:43399 every 8 connection(s)
I20260812 06:19:17.708683  1161 heartbeater.cc:344] Connected to a master server at 127.0.144.254:38139
I20260812 06:19:17.708791  1161 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:17.709004  1161 heartbeater.cc:507] Master 127.0.144.254:38139 requested a full tablet report, sending...
I20260812 06:19:17.709615   952 ts_manager.cc:194] Registered new tserver with Master: 51be7ae83c8e49879e8e9d13475ce935 (127.0.144.193:43399)
I20260812 06:19:17.709735   579 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005582446s
I20260812 06:19:17.710341   952 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48200
I20260812 06:19:17.716238   952 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48214:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:17.724345  1113 tablet_service.cc:1511] Processing CreateTablet for tablet f2206bcd8a4f4d11b83e39861e981225 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ef74f7ffe9b34533b8e42cb1f8f99005]), partition=
I20260812 06:19:17.724588  1113 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f2206bcd8a4f4d11b83e39861e981225. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:17.726382  1181 tablet_bootstrap.cc:492] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Bootstrap starting.
I20260812 06:19:17.727306  1181 tablet_bootstrap.cc:654] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:17.728262  1181 tablet_bootstrap.cc:492] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: No bootstrap required, opened a new log
I20260812 06:19:17.728335  1181 ts_tablet_manager.cc:1403] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:17.728718  1181 raft_consensus.cc:359] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51be7ae83c8e49879e8e9d13475ce935" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 43399 } }
I20260812 06:19:17.728804  1181 raft_consensus.cc:385] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:17.728837  1181 raft_consensus.cc:740] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 51be7ae83c8e49879e8e9d13475ce935, State: Initialized, Role: FOLLOWER
I20260812 06:19:17.728963  1181 consensus_queue.cc:260] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [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: "51be7ae83c8e49879e8e9d13475ce935" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 43399 } }
I20260812 06:19:17.729035  1181 raft_consensus.cc:399] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:17.729072  1181 raft_consensus.cc:493] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:17.729122  1181 raft_consensus.cc:3060] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:17.729993  1181 raft_consensus.cc:515] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51be7ae83c8e49879e8e9d13475ce935" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 43399 } }
I20260812 06:19:17.730111  1181 leader_election.cc:304] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [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: 51be7ae83c8e49879e8e9d13475ce935; no voters: 
I20260812 06:19:17.730293  1181 leader_election.cc:290] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:17.730398  1184 raft_consensus.cc:2804] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:17.730585  1181 ts_tablet_manager.cc:1434] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:17.730615  1161 heartbeater.cc:499] Master 127.0.144.254:38139 was elected leader, sending a full tablet report...
I20260812 06:19:17.730631  1184 raft_consensus.cc:697] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 1 LEADER]: Becoming Leader. State: Replica: 51be7ae83c8e49879e8e9d13475ce935, State: Running, Role: LEADER
I20260812 06:19:17.730857  1184 consensus_queue.cc:237] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [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: "51be7ae83c8e49879e8e9d13475ce935" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 43399 } }
I20260812 06:19:17.732066   952 catalog_manager.cc:5719] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 reported cstate change: term changed from 0 to 1, leader changed from <none> to 51be7ae83c8e49879e8e9d13475ce935 (127.0.144.193). New cstate: current_term: 1 leader_uuid: "51be7ae83c8e49879e8e9d13475ce935" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51be7ae83c8e49879e8e9d13475ce935" member_type: VOTER last_known_addr { host: "127.0.144.193" port: 43399 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:17.785301   579 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.016s	sys 0.007s
I20260812 06:19:17.954649  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225): perf score=23.023690
I20260812 06:19:18.110422  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.156s	user 0.101s	sys 0.051s Metrics: {"bytes_written":13497196,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":885,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42670,"lbm_writes_lt_1ms":886,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1280,"update_count":1645}
I20260812 06:19:18.111048  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling LogGCOp(f2206bcd8a4f4d11b83e39861e981225): free 20743880 bytes of WAL
I20260812 06:19:18.111241  1073 log_reader.cc:385] T f2206bcd8a4f4d11b83e39861e981225: removed 2 log segments from log reader
I20260812 06:19:18.111285  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000001 (ops 1-6)
I20260812 06:19:18.111323  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000002 (ops 7-11)
I20260812 06:19:18.115000  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: LogGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:18.115357  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225): 20513816 bytes on disk
I20260812 06:19:18.115710  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.116146  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:18.126369  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4020613,"delete_count":0,"lbm_write_time_us":3672,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:18.126695  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.196750
I20260812 06:19:18.136938  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:19:18.137272  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:18.301566  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.164s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815784,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":773,"lbm_read_time_us":11577,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26260,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":309,"threads_started":5,"update_count":2500}
I20260812 06:19:18.302130  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:18.347203  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.045s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":19945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.347680  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:18.499648  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.152s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713148,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":275,"lbm_read_time_us":11540,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22491,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:19:18.500218  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:18.546517  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.046s	user 0.024s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17468,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.547010  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:18.561950  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.562551  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:18.745673  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.183s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":11354,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27572,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:18.746187  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:18.796150  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.050s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20632,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.796640  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:18.807209  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.807639  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:18.964463  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.157s	user 0.073s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":502,"lbm_read_time_us":9172,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28689,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:18.964941  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:19.012795  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.048s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18774,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.013340  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:19.023880  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.024427  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:19.175798  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.151s	user 0.115s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":9753,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27720,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:19.176407  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:19.223869  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20264,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.224309  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:19.234452  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.235111  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:19.261291  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":35,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1309,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1338,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:19.261832  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling LogGCOp(f2206bcd8a4f4d11b83e39861e981225): free 121006436 bytes of WAL
I20260812 06:19:19.262037  1073 log_reader.cc:385] T f2206bcd8a4f4d11b83e39861e981225: removed 12 log segments from log reader
I20260812 06:19:19.262081  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000003 (ops 12-16)
I20260812 06:19:19.262109  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000004 (ops 17-21)
I20260812 06:19:19.262140  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000005 (ops 22-26)
I20260812 06:19:19.262173  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000006 (ops 27-31)
I20260812 06:19:19.262213  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000007 (ops 32-36)
I20260812 06:19:19.262245  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000008 (ops 37-40)
I20260812 06:19:19.262275  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000009 (ops 41-45)
I20260812 06:19:19.262307  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000010 (ops 46-50)
I20260812 06:19:19.262338  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000011 (ops 51-55)
I20260812 06:19:19.262368  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000012 (ops 56-60)
I20260812 06:19:19.262399  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000013 (ops 61-65)
I20260812 06:19:19.262430  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000014 (ops 66-70)
I20260812 06:19:19.284152  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: LogGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:19.284487  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=3.181125
I20260812 06:19:19.297942  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.013s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:19.298429  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225): 462 bytes on disk
I20260812 06:19:19.298812  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.299279  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:19.308300  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3348,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.308832  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:19.538463  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.229s	user 0.125s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":117,"lbm_read_time_us":14134,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35058,"lbm_writes_lt_1ms":743,"mutex_wait_us":48,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:19.539050  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=18.063937
I20260812 06:19:19.595781  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.057s	user 0.036s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":21703,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:19.596266  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:19.606366  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.606784  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:19.801139  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.194s	user 0.129s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":339,"lbm_read_time_us":13619,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34307,"lbm_writes_lt_1ms":643,"mutex_wait_us":248,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:19.802011  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:19.848284  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.046s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20780,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.848788  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:19.860177  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.860574  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:20.020874  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.160s	user 0.095s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":11879,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27476,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:19:20.021462  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:20.075265  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.054s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20373,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.075793  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.088003  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.088467  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:20.271930  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.183s	user 0.122s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1311,"lbm_read_time_us":13928,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30808,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:20.272431  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:20.324158  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.052s	user 0.027s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18336,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.324667  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.336042  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.336511  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:20.524677  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.188s	user 0.115s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":823,"lbm_read_time_us":12933,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34359,"lbm_writes_lt_1ms":543,"mutex_wait_us":257,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.525252  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:20.574227  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.049s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22018,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.574750  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.594830  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.020s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.595443  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:20.632061  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.036s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":151,"dirs.run_wall_time_us":1292,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1854,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:20.632658  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling LogGCOp(f2206bcd8a4f4d11b83e39861e981225): free 115490125 bytes of WAL
I20260812 06:19:20.632848  1073 log_reader.cc:385] T f2206bcd8a4f4d11b83e39861e981225: removed 11 log segments from log reader
I20260812 06:19:20.632889  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000015 (ops 71-75)
I20260812 06:19:20.632925  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000016 (ops 76-80)
I20260812 06:19:20.632957  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000017 (ops 81-85)
I20260812 06:19:20.632982  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000018 (ops 86-90)
I20260812 06:19:20.633013  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000019 (ops 91-95)
I20260812 06:19:20.633054  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000020 (ops 96-100)
I20260812 06:19:20.633085  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000021 (ops 101-105)
I20260812 06:19:20.633116  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000022 (ops 106-110)
I20260812 06:19:20.633145  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000023 (ops 111-115)
I20260812 06:19:20.633176  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000024 (ops 116-120)
I20260812 06:19:20.633206  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000025 (ops 121-124)
I20260812 06:19:20.652925  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: LogGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:19:20.653448  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.673437  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.020s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.673835  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.683295  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.683717  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:20.913282  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.229s	user 0.132s	sys 0.089s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3382,"lbm_read_time_us":14429,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37970,"lbm_writes_lt_1ms":743,"mutex_wait_us":2356,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:19:20.913940  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=18.063937
I20260812 06:19:20.975579  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.061s	user 0.047s	sys 0.004s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23183,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.976064  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225): 447 bytes on disk
I20260812 06:19:20.976457  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: UndoDeltaBlockGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.977015  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:20.987538  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.988060  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:21.169510  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.181s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":12176,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29195,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25216,"update_count":3000}
I20260812 06:19:21.170117  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:21.211074  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.041s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17778,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.211666  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:21.232584  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.233050  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:21.389752  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.157s	user 0.126s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":11717,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27506,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:19:21.390304  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:21.448159  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.058s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22185,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.448694  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:21.458356  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.458840  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:21.619899  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.161s	user 0.096s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":863,"lbm_read_time_us":11551,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26241,"lbm_writes_lt_1ms":543,"mutex_wait_us":265,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:21.620434  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:21.674461  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.054s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.675040  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:21.684724  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.685111  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:21.862462  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.177s	user 0.105s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":131,"lbm_read_time_us":12879,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27055,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:19:21.863085  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:21.919646  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.056s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19838,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.920238  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=2.188937
I20260812 06:19:21.930249  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.930727  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:21.957691  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushMRSOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1189,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1298,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:21.958472  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:22.130349  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.172s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":12185,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27136,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:19:22.131023  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling LogGCOp(f2206bcd8a4f4d11b83e39861e981225): free 121006622 bytes of WAL
I20260812 06:19:22.131240  1073 log_reader.cc:385] T f2206bcd8a4f4d11b83e39861e981225: removed 12 log segments from log reader
I20260812 06:19:22.131282  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000026 (ops 125-129)
I20260812 06:19:22.131320  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000027 (ops 130-134)
I20260812 06:19:22.131383  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000028 (ops 135-139)
I20260812 06:19:22.131419  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000029 (ops 140-144)
I20260812 06:19:22.131474  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000030 (ops 145-149)
I20260812 06:19:22.131510  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000031 (ops 150-154)
I20260812 06:19:22.131563  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000032 (ops 155-159)
I20260812 06:19:22.131598  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000033 (ops 160-164)
I20260812 06:19:22.131654  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000034 (ops 165-169)
I20260812 06:19:22.131687  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000035 (ops 170-174)
I20260812 06:19:22.131743  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000036 (ops 175-178)
I20260812 06:19:22.131778  1073 log.cc:1079] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: Deleting log segment in path: /tmp/dist-test-taskfWW1ef/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552598986-579-0/minicluster-data/ts-0-root/wals/f2206bcd8a4f4d11b83e39861e981225/wal-000000037 (ops 179-183)
I20260812 06:19:22.159399  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: LogGCOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.028s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:19:22.159904  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=17.071750
I20260812 06:19:22.218703  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.059s	user 0.039s	sys 0.015s Metrics: {"bytes_written":19281594,"delete_count":0,"lbm_write_time_us":23262,"lbm_writes_lt_1ms":473,"reinsert_count":0,"update_count":2350}
I20260812 06:19:22.219235  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=4.173312
I20260812 06:19:22.231666  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":5333390,"delete_count":0,"lbm_write_time_us":4940,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:19:22.232069  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:22.407243   579 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.622s	user 1.630s	sys 0.190s
I20260812 06:19:22.412555  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.180s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":13528,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30638,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:19:22.412966  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225): perf score=14.095187
I20260812 06:19:22.442669  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: FlushDeltaMemStoresOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":13766,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.443183  1162 maintenance_manager.cc:419] P 51be7ae83c8e49879e8e9d13475ce935: Scheduling MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225): perf score=1.000000
I20260812 06:19:22.479959   579 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:19:22.480444   579 tablet_server.cc:179] TabletServer@127.0.144.193:0 shutting down...
I20260812 06:19:22.576479  1073 maintenance_manager.cc:643] P 51be7ae83c8e49879e8e9d13475ce935: MajorDeltaCompactionOp(f2206bcd8a4f4d11b83e39861e981225) complete. Timing: real 0.133s	user 0.076s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":342,"lbm_read_time_us":7325,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24216,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:19:22.577100   579 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:22.577360   579 tablet_replica.cc:333] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935: stopping tablet replica
I20260812 06:19:22.577478   579 raft_consensus.cc:2243] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.577639   579 raft_consensus.cc:2272] T f2206bcd8a4f4d11b83e39861e981225 P 51be7ae83c8e49879e8e9d13475ce935 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.591755   579 tablet_server.cc:196] TabletServer@127.0.144.193:0 shutdown complete.
I20260812 06:19:22.614847   579 master.cc:562] Master@127.0.144.254:38139 shutting down...
I20260812 06:19:22.617900   579 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.618058   579 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.618124   579 tablet_replica.cc:333] T 00000000000000000000000000000000 P 266180cd2d6143bfbf7e0777612b8126: stopping tablet replica
I20260812 06:19:22.630059   579 master.cc:584] Master@127.0.144.254:38139 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5123 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10101 ms total)

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