[==========] 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:24.205464 31047 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.81.254:41847
I20260812 06:19:24.206424 31047 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:24.207010 31047 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.213495 31056 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:24.213543 31058 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:24.213658 31047 server_base.cc:1061] running on GCE node
W20260812 06:19:24.213845 31055 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:24.214322 31047 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.214454 31047 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:24.214520 31047 hybrid_clock.cc:648] HybridClock initialized: now 1786515564214518 us; error 0 us; skew 500 ppm
I20260812 06:19:24.216246 31047 webserver.cc:533] Webserver started at http://127.30.81.254:43947/ using document root <none> and password file <none>
I20260812 06:19:24.216795 31047 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.216879 31047 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.217108 31047 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.218787 31047 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/master-0-root/instance:
uuid: "ac3d8205850045f295303c43d9cca82a"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-8hhm"
I20260812 06:19:24.222131 31047 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:19:24.224184 31067 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:24.225255 31047 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.225389 31047 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/master-0-root
uuid: "ac3d8205850045f295303c43d9cca82a"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-8hhm"
I20260812 06:19:24.225492 31047 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-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:24.246968 31047 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.247627 31047 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:24.247809 31047 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:24.255733 31047 rpc_server.cc:307] RPC server started. Bound to: 127.30.81.254:41847
I20260812 06:19:24.255751 31149 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.81.254:41847 every 8 connection(s)
I20260812 06:19:24.258088 31153 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:24.263526 31153 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: Bootstrap starting.
I20260812 06:19:24.265915 31153 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:24.266927 31153 log.cc:826] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:24.268568 31153 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: No bootstrap required, opened a new log
I20260812 06:19:24.271252 31153 raft_consensus.cc:359] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER }
I20260812 06:19:24.271406 31153 raft_consensus.cc:385] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:24.271466 31153 raft_consensus.cc:740] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ac3d8205850045f295303c43d9cca82a, State: Initialized, Role: FOLLOWER
I20260812 06:19:24.272037 31153 consensus_queue.cc:260] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [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: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER }
I20260812 06:19:24.272200 31153 raft_consensus.cc:399] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:24.272274 31153 raft_consensus.cc:493] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:24.272446 31153 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.273254 31153 raft_consensus.cc:515] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER }
I20260812 06:19:24.273706 31153 leader_election.cc:304] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [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: ac3d8205850045f295303c43d9cca82a; no voters: 
I20260812 06:19:24.274022 31153 leader_election.cc:290] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.274158 31158 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.274415 31158 raft_consensus.cc:697] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 1 LEADER]: Becoming Leader. State: Replica: ac3d8205850045f295303c43d9cca82a, State: Running, Role: LEADER
I20260812 06:19:24.274806 31158 consensus_queue.cc:237] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [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: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER }
I20260812 06:19:24.274989 31153 sys_catalog.cc:565] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:24.276674 31160 sys_catalog.cc:455] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [sys.catalog]: SysCatalogTable state changed. Reason: New leader ac3d8205850045f295303c43d9cca82a. Latest consensus state: current_term: 1 leader_uuid: "ac3d8205850045f295303c43d9cca82a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER } }
I20260812 06:19:24.276785 31160 sys_catalog.cc:458] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:24.276659 31159 sys_catalog.cc:455] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ac3d8205850045f295303c43d9cca82a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac3d8205850045f295303c43d9cca82a" member_type: VOTER } }
I20260812 06:19:24.277055 31159 sys_catalog.cc:458] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:24.277252 31047 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:24.279238 31182 catalog_manager.cc:1594] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:24.279315 31182 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:24.279371 31179 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:24.280217 31179 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:24.284586 31179 catalog_manager.cc:1383] Generated new cluster ID: 7c160d4af6664ea690ea32576221ab2f
I20260812 06:19:24.284649 31179 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:24.300453 31179 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:24.301426 31179 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:24.315279 31179 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: Generated new TSK 0
I20260812 06:19:24.315960 31179 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:24.342228 31047 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.345412 31189 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:24.345513 31190 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:24.345515 31047 server_base.cc:1061] running on GCE node
W20260812 06:19:24.345794 31195 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:24.346005 31047 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.346061 31047 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:24.346093 31047 hybrid_clock.cc:648] HybridClock initialized: now 1786515564346093 us; error 0 us; skew 500 ppm
I20260812 06:19:24.347018 31047 webserver.cc:533] Webserver started at http://127.30.81.193:40903/ using document root <none> and password file <none>
I20260812 06:19:24.347193 31047 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.347250 31047 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.347318 31047 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.347754 31047 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/instance:
uuid: "3b496e831e1147629bb1b1e759f42038"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-8hhm"
I20260812 06:19:24.349593 31047 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.350649 31204 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:24.350936 31047 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:24.350998 31047 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root
uuid: "3b496e831e1147629bb1b1e759f42038"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-8hhm"
I20260812 06:19:24.351084 31047 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-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:24.359938 31047 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.360432 31047 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:24.360965 31047 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:24.361893 31047 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:24.361948 31047 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.362017 31047 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:24.362057 31047 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.368780 31047 rpc_server.cc:307] RPC server started. Bound to: 127.30.81.193:37607
I20260812 06:19:24.368818 31306 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.81.193:37607 every 8 connection(s)
I20260812 06:19:24.378931 31308 heartbeater.cc:344] Connected to a master server at 127.30.81.254:41847
I20260812 06:19:24.379184 31308 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:24.379664 31308 heartbeater.cc:507] Master 127.30.81.254:41847 requested a full tablet report, sending...
I20260812 06:19:24.381100 31089 ts_manager.cc:194] Registered new tserver with Master: 3b496e831e1147629bb1b1e759f42038 (127.30.81.193:37607)
I20260812 06:19:24.381748 31047 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012297772s
I20260812 06:19:24.382505 31089 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45348
I20260812 06:19:24.391209 31089 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45356:
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:24.404330 31245 tablet_service.cc:1511] Processing CreateTablet for tablet 6e4648c38d1842bbae18bc085120802b (DEFAULT_TABLE table=heavy-update-compaction-test [id=47508bcc88224d5b8ea6329079e53d07]), partition=
I20260812 06:19:24.404805 31245 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6e4648c38d1842bbae18bc085120802b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:24.407557 31331 tablet_bootstrap.cc:492] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Bootstrap starting.
I20260812 06:19:24.408675 31331 tablet_bootstrap.cc:654] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:24.409832 31331 tablet_bootstrap.cc:492] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: No bootstrap required, opened a new log
I20260812 06:19:24.409914 31331 ts_tablet_manager.cc:1403] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.410526 31331 raft_consensus.cc:359] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b496e831e1147629bb1b1e759f42038" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 37607 } }
I20260812 06:19:24.410643 31331 raft_consensus.cc:385] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:24.410666 31331 raft_consensus.cc:740] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3b496e831e1147629bb1b1e759f42038, State: Initialized, Role: FOLLOWER
I20260812 06:19:24.410837 31331 consensus_queue.cc:260] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [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: "3b496e831e1147629bb1b1e759f42038" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 37607 } }
I20260812 06:19:24.410903 31331 raft_consensus.cc:399] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:24.410952 31331 raft_consensus.cc:493] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:24.411005 31331 raft_consensus.cc:3060] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.411751 31331 raft_consensus.cc:515] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b496e831e1147629bb1b1e759f42038" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 37607 } }
I20260812 06:19:24.411866 31331 leader_election.cc:304] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [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: 3b496e831e1147629bb1b1e759f42038; no voters: 
I20260812 06:19:24.412107 31331 leader_election.cc:290] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.412429 31334 raft_consensus.cc:2804] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.412475 31331 ts_tablet_manager.cc:1434] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:24.412771 31334 raft_consensus.cc:697] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 1 LEADER]: Becoming Leader. State: Replica: 3b496e831e1147629bb1b1e759f42038, State: Running, Role: LEADER
I20260812 06:19:24.412961 31334 consensus_queue.cc:237] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [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: "3b496e831e1147629bb1b1e759f42038" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 37607 } }
I20260812 06:19:24.412981 31308 heartbeater.cc:499] Master 127.30.81.254:41847 was elected leader, sending a full tablet report...
I20260812 06:19:24.415793 31089 catalog_manager.cc:5719] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3b496e831e1147629bb1b1e759f42038 (127.30.81.193). New cstate: current_term: 1 leader_uuid: "3b496e831e1147629bb1b1e759f42038" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b496e831e1147629bb1b1e759f42038" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 37607 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:24.484416 31047 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.004s	sys 0.021s
I20260812 06:19:24.620280 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushMRSOp(6e4648c38d1842bbae18bc085120802b): perf score=15.086190
I20260812 06:19:24.781924 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushMRSOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.161s	user 0.119s	sys 0.040s Metrics: {"bytes_written":11897252,"cfile_init":1,"compiler_manager_pool.queue_time_us":279,"delete_count":0,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":933,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42945,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":162,"threads_started":1,"update_count":1450}
I20260812 06:19:24.783000 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling LogGCOp(6e4648c38d1842bbae18bc085120802b): free 20743880 bytes of WAL
I20260812 06:19:24.783315 31209 log_reader.cc:385] T 6e4648c38d1842bbae18bc085120802b: removed 2 log segments from log reader
I20260812 06:19:24.783394 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000001 (ops 1-6)
I20260812 06:19:24.783468 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000002 (ops 7-11)
I20260812 06:19:24.788007 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: LogGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:24.788404 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b): 12719217 bytes on disk
I20260812 06:19:24.788985 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b) 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:24.789450 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:24.806016 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.806540 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:24.946455 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262039,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1120,"lbm_read_time_us":11270,"lbm_reads_lt_1ms":454,"lbm_write_time_us":26320,"lbm_writes_lt_1ms":433,"mutex_wait_us":161,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":370,"threads_started":5,"update_count":1950}
I20260812 06:19:24.947062 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:24.988931 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.042s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17497,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.989482 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.002493 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.003032 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:25.120896 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.118s	user 0.096s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":466,"lbm_read_time_us":9839,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25491,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:19:25.121477 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:25.161648 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.040s	user 0.012s	sys 0.027s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18491,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.162159 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.174028 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.174487 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:25.304628 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.130s	user 0.096s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":11495,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26961,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:25.305251 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:25.359818 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.054s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16925,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.360344 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.371546 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.372046 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:25.534541 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.162s	user 0.100s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":594,"lbm_read_time_us":12406,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27553,"lbm_writes_lt_1ms":443,"mutex_wait_us":199,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:25.535338 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:25.580070 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.045s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17268,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.580497 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.592211 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.592902 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:25.728123 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.135s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":140,"lbm_read_time_us":9777,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28360,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:19:25.728734 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:25.769646 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17071,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:25.770150 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.781965 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.782428 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:25.913007 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.130s	user 0.094s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":10510,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25729,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":855936,"update_count":2000}
I20260812 06:19:25.913568 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:25.965337 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.052s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18575,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.965816 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:25.977560 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.978039 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:26.102712 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.124s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1036,"lbm_read_time_us":9964,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24334,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:26.103364 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:26.157660 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.054s	user 0.022s	sys 0.022s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.158254 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:26.169188 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.169765 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushMRSOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:26.215292 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushMRSOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.045s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1462,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1664,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:26.216223 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling LogGCOp(6e4648c38d1842bbae18bc085120802b): free 128867446 bytes of WAL
I20260812 06:19:26.216439 31209 log_reader.cc:385] T 6e4648c38d1842bbae18bc085120802b: removed 13 log segments from log reader
I20260812 06:19:26.216481 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000003 (ops 12-16)
I20260812 06:19:26.216509 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000004 (ops 17-20)
I20260812 06:19:26.216573 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000005 (ops 21-25)
I20260812 06:19:26.216606 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000006 (ops 26-30)
I20260812 06:19:26.216652 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000007 (ops 31-34)
I20260812 06:19:26.216691 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000008 (ops 35-39)
I20260812 06:19:26.216734 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000009 (ops 40-44)
I20260812 06:19:26.216775 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000010 (ops 45-49)
I20260812 06:19:26.216814 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000011 (ops 50-54)
I20260812 06:19:26.216853 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000012 (ops 55-58)
I20260812 06:19:26.216892 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000013 (ops 59-63)
I20260812 06:19:26.216931 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000014 (ops 64-68)
I20260812 06:19:26.216969 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000015 (ops 69-73)
I20260812 06:19:26.246147 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: LogGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:26.246537 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=3.181125
I20260812 06:19:26.267211 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.020s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7308,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:26.267751 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:26.283288 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6192,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.283874 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:26.503787 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.220s	user 0.162s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":254,"lbm_read_time_us":15416,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37951,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20992,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:26.504482 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:26.570279 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.065s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22284,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.570789 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:26.582895 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.583387 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b): 483 bytes on disk
I20260812 06:19:26.583815 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.584241 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:26.767078 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.183s	user 0.114s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1022,"lbm_read_time_us":13273,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32029,"lbm_writes_lt_1ms":543,"mutex_wait_us":352,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:26.767666 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:26.827749 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.060s	user 0.039s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21216,"lbm_writes_lt_1ms":403,"mutex_wait_us":1,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.828303 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:26.841176 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.841718 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:27.021067 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.179s	user 0.123s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":761,"lbm_read_time_us":13163,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30204,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.021757 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:27.084904 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.063s	user 0.039s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.085496 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:27.096087 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.096544 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:27.273388 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.177s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":12099,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30538,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.274107 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=11.118625
I20260812 06:19:27.309805 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.036s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14920,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.310492 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:27.327418 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.327986 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:27.491127 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.163s	user 0.104s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":7567,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23253,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":57088,"update_count":2000}
I20260812 06:19:27.491736 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:27.542373 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.050s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22787,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.542945 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:27.559219 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.559780 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:27.717521 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.158s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1096,"lbm_read_time_us":8813,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33550,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:27.718185 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=11.118625
I20260812 06:19:27.754511 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.036s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15553,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.755103 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:27.771137 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6445,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.771834 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushMRSOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:27.798828 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushMRSOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":316,"dirs.run_wall_time_us":1431,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1632,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:27.799626 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling LogGCOp(6e4648c38d1842bbae18bc085120802b): free 121006454 bytes of WAL
I20260812 06:19:27.799939 31209 log_reader.cc:385] T 6e4648c38d1842bbae18bc085120802b: removed 12 log segments from log reader
I20260812 06:19:27.800045 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000016 (ops 74-78)
I20260812 06:19:27.800137 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000017 (ops 79-83)
I20260812 06:19:27.800216 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000018 (ops 84-88)
I20260812 06:19:27.800285 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000019 (ops 89-93)
I20260812 06:19:27.800351 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000020 (ops 94-98)
I20260812 06:19:27.800401 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000021 (ops 99-103)
I20260812 06:19:27.800478 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000022 (ops 104-108)
I20260812 06:19:27.800524 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000023 (ops 109-113)
I20260812 06:19:27.800570 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000024 (ops 114-118)
I20260812 06:19:27.800626 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000025 (ops 119-122)
I20260812 06:19:27.800709 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000026 (ops 123-127)
I20260812 06:19:27.800773 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000027 (ops 128-132)
I20260812 06:19:27.829088 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: LogGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:27.829486 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=6.157687
I20260812 06:19:27.859225 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.030s	user 0.013s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12939,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:27.859730 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b): 470 bytes on disk
I20260812 06:19:27.860193 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b) 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:27.860678 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:28.022372 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.162s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":6972,"dirs.run_cpu_time_us":485,"dirs.run_wall_time_us":2822,"lbm_read_time_us":10825,"lbm_reads_lt_1ms":669,"lbm_write_time_us":33849,"lbm_writes_lt_1ms":643,"mutex_wait_us":3242,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3000}
I20260812 06:19:28.023383 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:28.075416 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.052s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24272,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.076159 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=3.181125
I20260812 06:19:28.097802 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.021s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6548,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:28.098254 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:28.111327 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.111806 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:28.291646 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.180s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":793,"lbm_read_time_us":14185,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34015,"lbm_writes_lt_1ms":643,"mutex_wait_us":330,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":84480,"update_count":3000}
I20260812 06:19:28.292371 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:28.354436 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.062s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28181,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.355113 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:28.369503 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.369951 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:28.528378 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.158s	user 0.123s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11203,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29867,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:28.529157 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:28.581779 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.052s	user 0.033s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.582304 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:28.593904 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.594477 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:28.769443 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.175s	user 0.117s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":970,"lbm_read_time_us":11891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29022,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:28.770078 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=14.095187
I20260812 06:19:28.816228 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20598,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.816924 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:28.967878 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.151s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":248,"lbm_read_time_us":11428,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25279,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:28.968626 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:29.001332 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.032s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13913,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.002014 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:29.019345 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.019876 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:29.150488 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.130s	user 0.110s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1260,"lbm_read_time_us":9650,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26044,"lbm_writes_lt_1ms":443,"mutex_wait_us":608,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:29.151208 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:29.192329 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.041s	user 0.032s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.192870 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=2.188937
I20260812 06:19:29.204658 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.205118 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushMRSOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:29.236285 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushMRSOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1371,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1589,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:29.236925 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling LogGCOp(6e4648c38d1842bbae18bc085120802b): free 120553636 bytes of WAL
I20260812 06:19:29.237155 31209 log_reader.cc:385] T 6e4648c38d1842bbae18bc085120802b: removed 12 log segments from log reader
I20260812 06:19:29.237214 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000028 (ops 133-136)
I20260812 06:19:29.237289 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000029 (ops 137-141)
I20260812 06:19:29.237349 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000030 (ops 142-146)
I20260812 06:19:29.237396 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000031 (ops 147-151)
I20260812 06:19:29.237432 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000032 (ops 152-156)
I20260812 06:19:29.237463 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000033 (ops 157-161)
I20260812 06:19:29.237499 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000034 (ops 162-166)
I20260812 06:19:29.237535 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000035 (ops 167-170)
I20260812 06:19:29.237571 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000036 (ops 171-175)
I20260812 06:19:29.237607 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000037 (ops 176-180)
I20260812 06:19:29.237636 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000038 (ops 181-185)
I20260812 06:19:29.237672 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000039 (ops 186-190)
I20260812 06:19:29.267870 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: LogGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:29.268509 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=4.173312
I20260812 06:19:29.287122 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":5866705,"delete_count":0,"lbm_write_time_us":7799,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:19:29.287590 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling LogGCOp(6e4648c38d1842bbae18bc085120802b): free 11564893 bytes of WAL
I20260812 06:19:29.287820 31209 log_reader.cc:385] T 6e4648c38d1842bbae18bc085120802b: removed 1 log segments from log reader
I20260812 06:19:29.287863 31209 log.cc:1079] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/6e4648c38d1842bbae18bc085120802b/wal-000000040 (ops 191-194)
I20260812 06:19:29.290107 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: LogGCOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:29.290422 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=1.196750
I20260812 06:19:29.299129 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":2979,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:19:29.299600 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b): 473 bytes on disk
I20260812 06:19:29.300007 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: UndoDeltaBlockGCOp(6e4648c38d1842bbae18bc085120802b) 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:29.300529 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:29.424227 31047 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.940s	user 1.849s	sys 0.121s
I20260812 06:19:29.462878 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.162s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877299,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":10465,"lbm_reads_lt_1ms":670,"lbm_write_time_us":36323,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:29.463366 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b): perf score=10.126437
I20260812 06:19:29.494230 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: FlushDeltaMemStoresOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.031s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12847,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.494710 31310 maintenance_manager.cc:419] P 3b496e831e1147629bb1b1e759f42038: Scheduling MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b): perf score=1.000000
I20260812 06:19:29.496236 31047 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.000s	sys 0.002s
I20260812 06:19:29.496832 31047 tablet_server.cc:179] TabletServer@127.30.81.193:0 shutting down...
I20260812 06:19:29.588553 31209 maintenance_manager.cc:643] P 3b496e831e1147629bb1b1e759f42038: MajorDeltaCompactionOp(6e4648c38d1842bbae18bc085120802b) complete. Timing: real 0.094s	user 0.089s	sys 0.004s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":588,"lbm_read_time_us":6878,"lbm_reads_lt_1ms":367,"lbm_write_time_us":17858,"lbm_writes_lt_1ms":343,"mutex_wait_us":20,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":1500}
I20260812 06:19:29.589360 31047 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:29.589843 31047 tablet_replica.cc:333] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038: stopping tablet replica
I20260812 06:19:29.590080 31047 raft_consensus.cc:2243] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.600755 31047 raft_consensus.cc:2272] T 6e4648c38d1842bbae18bc085120802b P 3b496e831e1147629bb1b1e759f42038 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.616325 31047 tablet_server.cc:196] TabletServer@127.30.81.193:0 shutdown complete.
I20260812 06:19:29.624801 31047 master.cc:562] Master@127.30.81.254:41847 shutting down...
I20260812 06:19:29.629179 31047 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.629428 31047 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.629551 31047 tablet_replica.cc:333] T 00000000000000000000000000000000 P ac3d8205850045f295303c43d9cca82a: stopping tablet replica
I20260812 06:19:29.641988 31047 master.cc:584] Master@127.30.81.254:41847 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5530 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:29.735395 31047 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.81.254:41163
I20260812 06:19:29.735827 31047 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.738137 31362 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:29.738162 31363 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:29.738193 31047 server_base.cc:1061] running on GCE node
W20260812 06:19:29.738163 31368 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:29.738528 31047 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.738591 31047 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:29.738616 31047 hybrid_clock.cc:648] HybridClock initialized: now 1786515569738616 us; error 0 us; skew 500 ppm
I20260812 06:19:29.739436 31047 webserver.cc:533] Webserver started at http://127.30.81.254:43575/ using document root <none> and password file <none>
I20260812 06:19:29.739611 31047 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.739684 31047 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.739761 31047 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.740173 31047 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/master-0-root/instance:
uuid: "68ba4fcfd8df45538e8667747b021032"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-8hhm"
I20260812 06:19:29.741765 31047 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:29.742710 31379 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:29.742980 31047 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:29.743075 31047 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/master-0-root
uuid: "68ba4fcfd8df45538e8667747b021032"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-8hhm"
I20260812 06:19:29.743170 31047 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-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:29.752424 31047 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.752770 31047 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.756857 31047 rpc_server.cc:307] RPC server started. Bound to: 127.30.81.254:41163
I20260812 06:19:29.759366 31469 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.81.254:41163 every 8 connection(s)
I20260812 06:19:29.767091 31470 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:29.768967 31470 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032: Bootstrap starting.
I20260812 06:19:29.769888 31470 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.770955 31470 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032: No bootstrap required, opened a new log
I20260812 06:19:29.771387 31470 raft_consensus.cc:359] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER }
I20260812 06:19:29.771471 31470 raft_consensus.cc:385] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.771514 31470 raft_consensus.cc:740] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 68ba4fcfd8df45538e8667747b021032, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.771713 31470 consensus_queue.cc:260] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [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: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER }
I20260812 06:19:29.771790 31470 raft_consensus.cc:399] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.771813 31470 raft_consensus.cc:493] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.771863 31470 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.772591 31470 raft_consensus.cc:515] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER }
I20260812 06:19:29.772703 31470 leader_election.cc:304] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [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: 68ba4fcfd8df45538e8667747b021032; no voters: 
I20260812 06:19:29.772953 31470 leader_election.cc:290] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.773118 31475 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.773329 31475 raft_consensus.cc:697] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 1 LEADER]: Becoming Leader. State: Replica: 68ba4fcfd8df45538e8667747b021032, State: Running, Role: LEADER
I20260812 06:19:29.773468 31470 sys_catalog.cc:565] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:29.773488 31475 consensus_queue.cc:237] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [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: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER }
I20260812 06:19:29.773986 31477 sys_catalog.cc:455] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "68ba4fcfd8df45538e8667747b021032" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER } }
I20260812 06:19:29.774040 31482 sys_catalog.cc:455] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 68ba4fcfd8df45538e8667747b021032. Latest consensus state: current_term: 1 leader_uuid: "68ba4fcfd8df45538e8667747b021032" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68ba4fcfd8df45538e8667747b021032" member_type: VOTER } }
I20260812 06:19:29.774148 31477 sys_catalog.cc:458] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.774483 31482 sys_catalog.cc:458] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.774730 31488 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:29.775588 31488 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:29.775820 31047 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:29.777479 31488 catalog_manager.cc:1383] Generated new cluster ID: 0c901e89964344c1a10026401550184a
I20260812 06:19:29.777554 31488 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:29.783038 31488 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:29.783654 31488 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:29.795761 31488 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032: Generated new TSK 0
I20260812 06:19:29.795961 31488 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:29.808332 31047 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.810427 31509 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:29.810482 31508 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:29.810510 31511 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:29.810613 31047 server_base.cc:1061] running on GCE node
I20260812 06:19:29.810853 31047 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.810896 31047 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:29.810913 31047 hybrid_clock.cc:648] HybridClock initialized: now 1786515569810913 us; error 0 us; skew 500 ppm
I20260812 06:19:29.811815 31047 webserver.cc:533] Webserver started at http://127.30.81.193:45223/ using document root <none> and password file <none>
I20260812 06:19:29.811954 31047 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.811998 31047 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.812052 31047 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.812433 31047 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/instance:
uuid: "fdc819c96a92427ab0fb800a6fca76e4"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-8hhm"
I20260812 06:19:29.814085 31047 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:29.815194 31522 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:29.815471 31047 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:29.815537 31047 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root
uuid: "fdc819c96a92427ab0fb800a6fca76e4"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-8hhm"
I20260812 06:19:29.815627 31047 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-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:29.828264 31047 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.828608 31047 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.828876 31047 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:29.829424 31047 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:29.829463 31047 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.829521 31047 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:29.829573 31047 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.833660 31047 rpc_server.cc:307] RPC server started. Bound to: 127.30.81.193:41709
I20260812 06:19:29.835765 31626 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.81.193:41709 every 8 connection(s)
I20260812 06:19:29.844491 31627 heartbeater.cc:344] Connected to a master server at 127.30.81.254:41163
I20260812 06:19:29.844626 31627 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:29.844837 31627 heartbeater.cc:507] Master 127.30.81.254:41163 requested a full tablet report, sending...
I20260812 06:19:29.845523 31411 ts_manager.cc:194] Registered new tserver with Master: fdc819c96a92427ab0fb800a6fca76e4 (127.30.81.193:41709)
I20260812 06:19:29.845691 31047 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011034786s
I20260812 06:19:29.846537 31411 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44546
I20260812 06:19:29.853266 31411 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44556:
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:29.862236 31559 tablet_service.cc:1511] Processing CreateTablet for tablet 4efc533d57d34435a58f683051097f29 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6d8faf7351e4419cadf86369f9f97867]), partition=
I20260812 06:19:29.862540 31559 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4efc533d57d34435a58f683051097f29. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:29.864785 31645 tablet_bootstrap.cc:492] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Bootstrap starting.
I20260812 06:19:29.865736 31645 tablet_bootstrap.cc:654] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.866816 31645 tablet_bootstrap.cc:492] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: No bootstrap required, opened a new log
I20260812 06:19:29.866892 31645 ts_tablet_manager.cc:1403] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:29.867398 31645 raft_consensus.cc:359] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fdc819c96a92427ab0fb800a6fca76e4" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 41709 } }
I20260812 06:19:29.867523 31645 raft_consensus.cc:385] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.867563 31645 raft_consensus.cc:740] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fdc819c96a92427ab0fb800a6fca76e4, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.867699 31645 consensus_queue.cc:260] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [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: "fdc819c96a92427ab0fb800a6fca76e4" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 41709 } }
I20260812 06:19:29.867813 31645 raft_consensus.cc:399] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.867878 31645 raft_consensus.cc:493] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.867938 31645 raft_consensus.cc:3060] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.868664 31645 raft_consensus.cc:515] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fdc819c96a92427ab0fb800a6fca76e4" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 41709 } }
I20260812 06:19:29.868819 31645 leader_election.cc:304] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [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: fdc819c96a92427ab0fb800a6fca76e4; no voters: 
I20260812 06:19:29.869033 31645 leader_election.cc:290] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.869181 31648 raft_consensus.cc:2804] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.869412 31645 ts_tablet_manager.cc:1434] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:29.869433 31648 raft_consensus.cc:697] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 1 LEADER]: Becoming Leader. State: Replica: fdc819c96a92427ab0fb800a6fca76e4, State: Running, Role: LEADER
I20260812 06:19:29.869415 31627 heartbeater.cc:499] Master 127.30.81.254:41163 was elected leader, sending a full tablet report...
I20260812 06:19:29.869696 31648 consensus_queue.cc:237] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [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: "fdc819c96a92427ab0fb800a6fca76e4" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 41709 } }
I20260812 06:19:29.870952 31411 catalog_manager.cc:5719] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 reported cstate change: term changed from 0 to 1, leader changed from <none> to fdc819c96a92427ab0fb800a6fca76e4 (127.30.81.193). New cstate: current_term: 1 leader_uuid: "fdc819c96a92427ab0fb800a6fca76e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fdc819c96a92427ab0fb800a6fca76e4" member_type: VOTER last_known_addr { host: "127.30.81.193" port: 41709 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:29.932585 31047 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.018s	sys 0.004s
I20260812 06:19:30.086284 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushMRSOp(4efc533d57d34435a58f683051097f29): perf score=19.054940
I20260812 06:19:30.251255 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushMRSOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.165s	user 0.111s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":865,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44126,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:30.251925 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling LogGCOp(4efc533d57d34435a58f683051097f29): free 20743880 bytes of WAL
I20260812 06:19:30.252177 31530 log_reader.cc:385] T 4efc533d57d34435a58f683051097f29: removed 2 log segments from log reader
I20260812 06:19:30.252241 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000001 (ops 1-6)
I20260812 06:19:30.252297 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000002 (ops 7-11)
I20260812 06:19:30.257879 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: LogGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:30.258337 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29): 16411393 bytes on disk
I20260812 06:19:30.258890 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.259415 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:30.273106 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.273669 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:30.445080 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.171s	user 0.098s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1117,"lbm_read_time_us":12883,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27573,"lbm_writes_lt_1ms":443,"mutex_wait_us":174,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"thread_start_us":364,"threads_started":5,"update_count":2000}
I20260812 06:19:30.445863 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:30.489907 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.044s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20305,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.490387 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:30.676407 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.186s	user 0.134s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1413,"lbm_read_time_us":14373,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28432,"lbm_writes_lt_1ms":443,"mutex_wait_us":471,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:30.676860 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:30.734264 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.057s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24255,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.734783 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:30.751652 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.761179 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:30.948921 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.188s	user 0.122s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1383,"lbm_read_time_us":14781,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31748,"lbm_writes_lt_1ms":543,"mutex_wait_us":370,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:30.949579 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:31.003647 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.054s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23057,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.004117 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:31.016119 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.016582 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:31.191922 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.175s	user 0.138s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":363,"lbm_read_time_us":14223,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32044,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:31.192425 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:31.250999 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.058s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.251554 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:31.268205 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.268689 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:31.433369 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.165s	user 0.106s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":678,"lbm_read_time_us":10977,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35093,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:19:31.434074 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:31.484002 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.050s	user 0.021s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18515,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.484582 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:31.496495 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.496927 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushMRSOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:31.526481 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushMRSOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.029s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1550,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2128,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:31.527035 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling LogGCOp(4efc533d57d34435a58f683051097f29): free 115943173 bytes of WAL
I20260812 06:19:31.527254 31530 log_reader.cc:385] T 4efc533d57d34435a58f683051097f29: removed 11 log segments from log reader
I20260812 06:19:31.527312 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000003 (ops 12-16)
I20260812 06:19:31.527369 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000004 (ops 17-21)
I20260812 06:19:31.527424 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000005 (ops 22-26)
I20260812 06:19:31.527467 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000006 (ops 27-31)
I20260812 06:19:31.527503 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000007 (ops 32-36)
I20260812 06:19:31.527537 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000008 (ops 37-41)
I20260812 06:19:31.527573 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000009 (ops 42-46)
I20260812 06:19:31.527609 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000010 (ops 47-51)
I20260812 06:19:31.527645 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000011 (ops 52-56)
I20260812 06:19:31.527683 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000012 (ops 57-61)
I20260812 06:19:31.527719 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000013 (ops 62-66)
I20260812 06:19:31.556381 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: LogGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.029s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:19:31.556852 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=3.181125
I20260812 06:19:31.570713 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5576,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:31.571167 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29): 447 bytes on disk
I20260812 06:19:31.571570 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.572075 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:31.584450 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4432,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.584998 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:31.830863 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.246s	user 0.175s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1042,"lbm_read_time_us":15336,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42556,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13568,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:31.831379 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=18.063937
I20260812 06:19:31.903028 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.070s	user 0.052s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31901,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.903872 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:31.922739 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.923270 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:32.166292 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.243s	user 0.162s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":435,"lbm_read_time_us":15684,"lbm_reads_lt_1ms":664,"lbm_write_time_us":41382,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35584,"update_count":3000}
I20260812 06:19:32.167061 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=18.063937
I20260812 06:19:32.238158 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.071s	user 0.032s	sys 0.024s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26611,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.238631 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:32.250927 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.251469 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:32.481113 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.229s	user 0.131s	sys 0.097s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1882,"lbm_read_time_us":18044,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37740,"lbm_writes_lt_1ms":643,"mutex_wait_us":401,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":3000}
I20260812 06:19:32.481976 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=17.071750
I20260812 06:19:32.553478 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.071s	user 0.045s	sys 0.015s Metrics: {"bytes_written":18871351,"delete_count":0,"lbm_write_time_us":27949,"lbm_writes_lt_1ms":463,"reinsert_count":0,"update_count":2300}
I20260812 06:19:32.553978 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=4.173312
I20260812 06:19:32.570789 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":7192,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:19:32.571261 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:32.786196 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.215s	user 0.138s	sys 0.070s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":16064,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34939,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:19:32.786949 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=18.063937
I20260812 06:19:32.841516 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.054s	user 0.040s	sys 0.012s Metrics: {"bytes_written":20512311,"delete_count":0,"lbm_write_time_us":24447,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.841998 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:33.015012 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.173s	user 0.094s	sys 0.077s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774567,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":157,"lbm_read_time_us":14000,"lbm_reads_lt_1ms":563,"lbm_write_time_us":29296,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:33.015694 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:33.068540 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.053s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18199,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.069193 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.094194 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.025s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.094683 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.105329 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.105815 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushMRSOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:33.141983 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushMRSOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.036s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1256,"drs_written":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":768}
I20260812 06:19:33.142598 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling LogGCOp(4efc533d57d34435a58f683051097f29): free 121006440 bytes of WAL
I20260812 06:19:33.142828 31530 log_reader.cc:385] T 4efc533d57d34435a58f683051097f29: removed 12 log segments from log reader
I20260812 06:19:33.142871 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000014 (ops 67-71)
I20260812 06:19:33.142899 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000015 (ops 72-76)
I20260812 06:19:33.142962 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000016 (ops 77-81)
I20260812 06:19:33.143003 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000017 (ops 82-86)
I20260812 06:19:33.143064 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000018 (ops 87-90)
I20260812 06:19:33.143110 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000019 (ops 91-95)
I20260812 06:19:33.143142 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000020 (ops 96-100)
I20260812 06:19:33.143174 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000021 (ops 101-105)
I20260812 06:19:33.143215 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000022 (ops 106-110)
I20260812 06:19:33.143249 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000023 (ops 111-115)
I20260812 06:19:33.143285 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000024 (ops 116-120)
I20260812 06:19:33.143324 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000025 (ops 121-125)
I20260812 06:19:33.172297 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: LogGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:33.172714 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29): 482 bytes on disk
I20260812 06:19:33.173139 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29) 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:33.173691 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.196432 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6523,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.196893 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling LogGCOp(4efc533d57d34435a58f683051097f29): free 12017940 bytes of WAL
I20260812 06:19:33.197095 31530 log_reader.cc:385] T 4efc533d57d34435a58f683051097f29: removed 1 log segments from log reader
I20260812 06:19:33.197137 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000026 (ops 126-130)
I20260812 06:19:33.199628 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: LogGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:33.199910 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.211372 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.211869 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:33.488159 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.276s	user 0.197s	sys 0.077s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082283,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":600,"lbm_read_time_us":19534,"lbm_reads_lt_1ms":875,"lbm_write_time_us":53064,"lbm_writes_lt_1ms":843,"mutex_wait_us":41,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":96,"threads_started":1,"update_count":4000}
I20260812 06:19:33.488873 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=18.063937
I20260812 06:19:33.551435 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.062s	user 0.036s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27468,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:33.552054 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.569399 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.569875 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:33.746518 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.176s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1303,"lbm_read_time_us":12929,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32147,"lbm_writes_lt_1ms":643,"mutex_wait_us":4,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3000}
I20260812 06:19:33.747232 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:33.793743 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.046s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20291,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.794265 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.820061 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.026s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.820664 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:33.830897 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.831315 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:34.013031 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.182s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1219,"lbm_read_time_us":15507,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35500,"lbm_writes_lt_1ms":643,"mutex_wait_us":399,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":3000}
I20260812 06:19:34.013792 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:34.067500 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.053s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.068063 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.084923 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.085486 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:34.244908 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.159s	user 0.112s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":520,"lbm_read_time_us":9189,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29418,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:34.245482 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:34.311344 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.066s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23668,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.311919 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.324106 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.324626 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:34.501710 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.177s	user 0.109s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":647,"lbm_read_time_us":13701,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31930,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:19:34.502271 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=14.095187
I20260812 06:19:34.567636 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.065s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22853,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.568238 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.579205 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.579710 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushMRSOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:34.620860 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushMRSOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1417,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1677,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:34.621680 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling LogGCOp(4efc533d57d34435a58f683051097f29): free 112239554 bytes of WAL
I20260812 06:19:34.621961 31530 log_reader.cc:385] T 4efc533d57d34435a58f683051097f29: removed 11 log segments from log reader
I20260812 06:19:34.622031 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000027 (ops 131-135)
I20260812 06:19:34.622072 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000028 (ops 136-140)
I20260812 06:19:34.622109 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000029 (ops 141-145)
I20260812 06:19:34.622136 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000030 (ops 146-150)
I20260812 06:19:34.622165 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000031 (ops 151-155)
I20260812 06:19:34.622187 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000032 (ops 156-160)
I20260812 06:19:34.622217 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000033 (ops 161-165)
I20260812 06:19:34.622249 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000034 (ops 166-170)
I20260812 06:19:34.622280 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000035 (ops 171-175)
I20260812 06:19:34.622310 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000036 (ops 176-180)
I20260812 06:19:34.622335 31530 log.cc:1079] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: Deleting log segment in path: /tmp/dist-test-task4r5q29/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564195001-31047-0/minicluster-data/ts-0-root/wals/4efc533d57d34435a58f683051097f29/wal-000000037 (ops 181-184)
I20260812 06:19:34.652668 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: LogGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:34.653273 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29): 463 bytes on disk
I20260812 06:19:34.653756 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: UndoDeltaBlockGCOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.654320 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.679358 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.025s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.679981 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.690920 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.691382 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:34.911949 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.220s	user 0.132s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":185,"lbm_read_time_us":16081,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39375,"lbm_writes_lt_1ms":743,"mutex_wait_us":30,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:34.913615 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=18.063937
I20260812 06:19:34.961207 31047 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.029s	user 1.807s	sys 0.224s
I20260812 06:19:34.965927 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.052s	user 0.021s	sys 0.029s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22968,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:34.966440 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29): perf score=2.188937
I20260812 06:19:34.982820 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: FlushDeltaMemStoresOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:19:34.983278 31628 maintenance_manager.cc:419] P fdc819c96a92427ab0fb800a6fca76e4: Scheduling MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29): perf score=1.000000
I20260812 06:19:35.017485 31047 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.056s	user 0.003s	sys 0.000s
I20260812 06:19:35.017994 31047 tablet_server.cc:179] TabletServer@127.30.81.193:0 shutting down...
I20260812 06:19:35.119899 31530 maintenance_manager.cc:643] P fdc819c96a92427ab0fb800a6fca76e4: MajorDeltaCompactionOp(4efc533d57d34435a58f683051097f29) complete. Timing: real 0.136s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_hit":403,"cfile_cache_hit_bytes":16493104,"cfile_cache_miss":229,"cfile_cache_miss_bytes":12383999,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":4782,"lbm_reads_lt_1ms":261,"lbm_write_time_us":28651,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":30720,"update_count":3000}
I20260812 06:19:35.120831 31047 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:35.121184 31047 tablet_replica.cc:333] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4: stopping tablet replica
I20260812 06:19:35.121363 31047 raft_consensus.cc:2243] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:35.121541 31047 raft_consensus.cc:2272] T 4efc533d57d34435a58f683051097f29 P fdc819c96a92427ab0fb800a6fca76e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:35.126881 31047 tablet_server.cc:196] TabletServer@127.30.81.193:0 shutdown complete.
I20260812 06:19:35.172806 31047 master.cc:562] Master@127.30.81.254:41163 shutting down...
I20260812 06:19:35.176488 31047 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:35.176656 31047 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:35.176707 31047 tablet_replica.cc:333] T 00000000000000000000000000000000 P 68ba4fcfd8df45538e8667747b021032: stopping tablet replica
I20260812 06:19:35.189118 31047 master.cc:584] Master@127.30.81.254:41163 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5548 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11079 ms total)

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