[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:53.900879  6954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.202.190:42085
I20260812 06:18:53.901829  6954 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:53.902392  6954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:53.907876  6962 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.908052  6954 server_base.cc:1061] running on GCE node
W20260812 06:18:53.909713  6963 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:53.909907  6965 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.910315  6954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.910418  6954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:53.910459  6954 hybrid_clock.cc:648] HybridClock initialized: now 1786515533910457 us; error 0 us; skew 500 ppm
I20260812 06:18:53.912012  6954 webserver.cc:533] Webserver started at http://127.6.202.190:40837/ using document root <none> and password file <none>
I20260812 06:18:53.912495  6954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.912556  6954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.912763  6954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.914309  6954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/master-0-root/instance:
uuid: "b78ed904d2684fc5a049fba1fb85de5f"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-266d"
I20260812 06:18:53.917459  6954 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:53.919287  6971 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.920176  6954 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:53.920279  6954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/master-0-root
uuid: "b78ed904d2684fc5a049fba1fb85de5f"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-266d"
I20260812 06:18:53.920359  6954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:53.941613  6954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.942207  6954 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:53.942364  6954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.949543  7064 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.202.190:42085 every 8 connection(s)
I20260812 06:18:53.949550  6954 rpc_server.cc:307] RPC server started. Bound to: 127.6.202.190:42085
I20260812 06:18:53.951658  7065 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:53.956732  7065 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: Bootstrap starting.
I20260812 06:18:53.958927  7065 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.959736  7065 log.cc:826] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:53.961201  7065 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: No bootstrap required, opened a new log
I20260812 06:18:53.963716  7065 raft_consensus.cc:359] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER }
I20260812 06:18:53.963864  7065 raft_consensus.cc:385] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.963908  7065 raft_consensus.cc:740] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b78ed904d2684fc5a049fba1fb85de5f, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.964387  7065 consensus_queue.cc:260] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [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: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER }
I20260812 06:18:53.964506  7065 raft_consensus.cc:399] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.964548  7065 raft_consensus.cc:493] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.964629  7065 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.965324  7065 raft_consensus.cc:515] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER }
I20260812 06:18:53.965677  7065 leader_election.cc:304] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [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: b78ed904d2684fc5a049fba1fb85de5f; no voters: 
I20260812 06:18:53.965911  7065 leader_election.cc:290] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.966045  7070 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.966257  7070 raft_consensus.cc:697] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 1 LEADER]: Becoming Leader. State: Replica: b78ed904d2684fc5a049fba1fb85de5f, State: Running, Role: LEADER
I20260812 06:18:53.966640  7070 consensus_queue.cc:237] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [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: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER }
I20260812 06:18:53.966739  7065 sys_catalog.cc:565] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:53.968303  7074 sys_catalog.cc:455] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [sys.catalog]: SysCatalogTable state changed. Reason: New leader b78ed904d2684fc5a049fba1fb85de5f. Latest consensus state: current_term: 1 leader_uuid: "b78ed904d2684fc5a049fba1fb85de5f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER } }
I20260812 06:18:53.968339  7073 sys_catalog.cc:455] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b78ed904d2684fc5a049fba1fb85de5f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b78ed904d2684fc5a049fba1fb85de5f" member_type: VOTER } }
I20260812 06:18:53.968428  7074 sys_catalog.cc:458] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.968428  7073 sys_catalog.cc:458] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.968812  6954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:53.970636  7100 catalog_manager.cc:1594] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:53.970698  7100 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:53.970815  7099 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:53.971709  7099 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:53.975862  7099 catalog_manager.cc:1383] Generated new cluster ID: 7d821c857b514d78bd0ee96f6d0387ed
I20260812 06:18:53.975922  7099 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:54.010018  7099 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:54.011210  7099 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:54.018886  7099 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: Generated new TSK 0
I20260812 06:18:54.019599  7099 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:54.033571  6954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:54.036363  7112 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:18:54.036464  6954 server_base.cc:1061] running on GCE node
W20260812 06:18:54.036545  7115 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:54.036630  7111 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:54.036832  6954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:54.036896  6954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:54.036917  6954 hybrid_clock.cc:648] HybridClock initialized: now 1786515534036918 us; error 0 us; skew 500 ppm
I20260812 06:18:54.037850  6954 webserver.cc:533] Webserver started at http://127.6.202.129:35293/ using document root <none> and password file <none>
I20260812 06:18:54.038013  6954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:54.038066  6954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:54.038141  6954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:54.038553  6954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/instance:
uuid: "ec200ef010994d57b7b08caa60f4a731"
format_stamp: "Formatted at 2026-08-12 06:18:54 on dist-test-slave-266d"
I20260812 06:18:54.040342  6954 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:54.041383  7123 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.041637  6954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:54.041715  6954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root
uuid: "ec200ef010994d57b7b08caa60f4a731"
format_stamp: "Formatted at 2026-08-12 06:18:54 on dist-test-slave-266d"
I20260812 06:18:54.041788  6954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:54.054895  6954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:54.055255  6954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:54.055655  6954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:54.056457  6954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:54.056510  6954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.056556  6954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:54.056586  6954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.062775  6954 rpc_server.cc:307] RPC server started. Bound to: 127.6.202.129:34773
I20260812 06:18:54.062830  7227 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.202.129:34773 every 8 connection(s)
I20260812 06:18:54.072988  7229 heartbeater.cc:344] Connected to a master server at 127.6.202.190:42085
I20260812 06:18:54.073231  7229 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:54.073634  7229 heartbeater.cc:507] Master 127.6.202.190:42085 requested a full tablet report, sending...
I20260812 06:18:54.074958  6997 ts_manager.cc:194] Registered new tserver with Master: ec200ef010994d57b7b08caa60f4a731 (127.6.202.129:34773)
I20260812 06:18:54.075068  6954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011693362s
I20260812 06:18:54.076054  6997 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44122
I20260812 06:18:54.083885  6997 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44136:
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:18:54.097488  7167 tablet_service.cc:1511] Processing CreateTablet for tablet 3b30d6a387314bb0a5d6639ce26ce0cc (DEFAULT_TABLE table=heavy-update-compaction-test [id=bb5a5c77a3ff4b56b63f53f5ea180049]), partition=
I20260812 06:18:54.097900  7167 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3b30d6a387314bb0a5d6639ce26ce0cc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:54.100148  7248 tablet_bootstrap.cc:492] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Bootstrap starting.
I20260812 06:18:54.101562  7248 tablet_bootstrap.cc:654] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:54.102806  7248 tablet_bootstrap.cc:492] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: No bootstrap required, opened a new log
I20260812 06:18:54.102914  7248 ts_tablet_manager.cc:1403] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:18:54.103389  7248 raft_consensus.cc:359] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec200ef010994d57b7b08caa60f4a731" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 34773 } }
I20260812 06:18:54.103513  7248 raft_consensus.cc:385] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:54.103556  7248 raft_consensus.cc:740] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec200ef010994d57b7b08caa60f4a731, State: Initialized, Role: FOLLOWER
I20260812 06:18:54.103683  7248 consensus_queue.cc:260] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [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: "ec200ef010994d57b7b08caa60f4a731" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 34773 } }
I20260812 06:18:54.103766  7248 raft_consensus.cc:399] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:54.103816  7248 raft_consensus.cc:493] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:54.103863  7248 raft_consensus.cc:3060] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:54.104768  7248 raft_consensus.cc:515] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec200ef010994d57b7b08caa60f4a731" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 34773 } }
I20260812 06:18:54.104926  7248 leader_election.cc:304] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [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: ec200ef010994d57b7b08caa60f4a731; no voters: 
I20260812 06:18:54.105136  7248 leader_election.cc:290] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:54.105867  7248 ts_tablet_manager.cc:1434] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:54.105865  7253 raft_consensus.cc:2804] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:54.106223  7253 raft_consensus.cc:697] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 1 LEADER]: Becoming Leader. State: Replica: ec200ef010994d57b7b08caa60f4a731, State: Running, Role: LEADER
I20260812 06:18:54.106323  7229 heartbeater.cc:499] Master 127.6.202.190:42085 was elected leader, sending a full tablet report...
I20260812 06:18:54.106411  7253 consensus_queue.cc:237] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [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: "ec200ef010994d57b7b08caa60f4a731" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 34773 } }
I20260812 06:18:54.108942  6997 catalog_manager.cc:5719] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 reported cstate change: term changed from 0 to 1, leader changed from <none> to ec200ef010994d57b7b08caa60f4a731 (127.6.202.129). New cstate: current_term: 1 leader_uuid: "ec200ef010994d57b7b08caa60f4a731" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec200ef010994d57b7b08caa60f4a731" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 34773 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:54.169153  6954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.024s	sys 0.000s
I20260812 06:18:54.313831  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=19.054940
I20260812 06:18:54.521196  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.207s	user 0.159s	sys 0.037s Metrics: {"bytes_written":16615024,"cfile_init":1,"compiler_manager_pool.queue_time_us":224,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":954,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46851,"lbm_writes_lt_1ms":872,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":337152,"thread_start_us":130,"threads_started":1,"update_count":2025}
I20260812 06:18:54.522353  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): free 20743880 bytes of WAL
I20260812 06:18:54.522657  7134 log_reader.cc:385] T 3b30d6a387314bb0a5d6639ce26ce0cc: removed 2 log segments from log reader
I20260812 06:18:54.522723  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000001 (ops 1-6)
I20260812 06:18:54.522780  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000002 (ops 7-11)
I20260812 06:18:54.527808  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:54.528168  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=6.157687
I20260812 06:18:54.549890  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.022s	user 0.013s	sys 0.008s Metrics: {"bytes_written":7589720,"delete_count":0,"lbm_write_time_us":9020,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:18:54.550326  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): 16821647 bytes on disk
I20260812 06:18:54.550838  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:18:54.551239  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:54.716979  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.166s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507861,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":484,"lbm_read_time_us":10115,"lbm_reads_lt_1ms":654,"lbm_write_time_us":28333,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":271,"threads_started":5,"update_count":2950}
I20260812 06:18:54.717475  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:54.758569  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.041s	user 0.037s	sys 0.000s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17043,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.759172  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:54.895638  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.136s	user 0.088s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":849,"lbm_read_time_us":9118,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21061,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:18:54.896124  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=10.126437
I20260812 06:18:54.923046  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":11308,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.923491  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:54.934806  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.935256  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.053968  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.119s	user 0.085s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":9366,"lbm_reads_lt_1ms":468,"lbm_write_time_us":19345,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":56576,"update_count":2000}
I20260812 06:18:55.054486  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=10.126437
I20260812 06:18:55.092401  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.038s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13222,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.092932  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.106192  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.106587  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.228742  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":641,"lbm_read_time_us":9479,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22694,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:18:55.229362  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=10.126437
I20260812 06:18:55.263837  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.034s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12850,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.264353  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.275591  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.276081  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.394860  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.118s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":422,"lbm_read_time_us":7319,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23164,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:18:55.395465  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=10.126437
I20260812 06:18:55.432403  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.037s	user 0.011s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12310,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.432885  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.442567  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.442974  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.576560  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.133s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":9470,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21376,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:18:55.577299  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=10.126437
I20260812 06:18:55.611847  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13788,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.612339  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.625708  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.626240  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.653925  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.027s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1233,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1364,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:55.654830  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): free 124710256 bytes of WAL
I20260812 06:18:55.655061  7134 log_reader.cc:385] T 3b30d6a387314bb0a5d6639ce26ce0cc: removed 12 log segments from log reader
I20260812 06:18:55.655107  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000003 (ops 12-16)
I20260812 06:18:55.655145  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000004 (ops 17-21)
I20260812 06:18:55.655177  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000005 (ops 22-26)
I20260812 06:18:55.655207  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000006 (ops 27-31)
I20260812 06:18:55.655237  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000007 (ops 32-36)
I20260812 06:18:55.655267  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000008 (ops 37-41)
I20260812 06:18:55.655297  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000009 (ops 42-46)
I20260812 06:18:55.655328  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000010 (ops 47-51)
I20260812 06:18:55.655357  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000011 (ops 52-56)
I20260812 06:18:55.655386  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000012 (ops 57-61)
I20260812 06:18:55.655416  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000013 (ops 62-66)
I20260812 06:18:55.655443  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000014 (ops 67-71)
I20260812 06:18:55.678561  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:55.678939  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=3.181125
I20260812 06:18:55.700839  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.022s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3808,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:55.701265  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): 463 bytes on disk
I20260812 06:18:55.701735  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.702152  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.711045  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3323,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.711405  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:55.908515  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.197s	user 0.137s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":376,"lbm_read_time_us":13634,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31461,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:55.909003  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:55.966848  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.058s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.967355  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:55.977394  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.977784  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:56.146409  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.168s	user 0.109s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":11216,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31405,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:18:56.146869  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=11.118625
I20260812 06:18:56.185254  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.038s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14779,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:56.185739  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.202176  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.016s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.202564  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.218194  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.015s	user 0.004s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.218621  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:56.389183  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.170s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":301,"lbm_read_time_us":12544,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27900,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:56.389739  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:56.450682  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.061s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24006,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.451189  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.463301  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.463963  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:56.625588  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.161s	user 0.105s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":129,"lbm_read_time_us":11272,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26199,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:56.626078  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=11.118625
I20260812 06:18:56.664604  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.038s	user 0.012s	sys 0.023s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17303,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:56.665198  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.681977  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.682516  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.693339  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.693929  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:56.853250  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.159s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":834,"lbm_read_time_us":12148,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28241,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:56.853732  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:56.900430  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.047s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20109,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.900925  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:56.910977  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.911537  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.060359  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.149s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":11332,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26119,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:57.060906  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:57.107417  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.046s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18069,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.107960  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:57.125314  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7025,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.125793  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.155121  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1251,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1754,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:57.155922  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): free 132571389 bytes of WAL
I20260812 06:18:57.156173  7134 log_reader.cc:385] T 3b30d6a387314bb0a5d6639ce26ce0cc: removed 13 log segments from log reader
I20260812 06:18:57.156230  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000015 (ops 72-76)
I20260812 06:18:57.156276  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000016 (ops 77-81)
I20260812 06:18:57.156328  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000017 (ops 82-86)
I20260812 06:18:57.156363  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000018 (ops 87-91)
I20260812 06:18:57.156400  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000019 (ops 92-96)
I20260812 06:18:57.156436  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000020 (ops 97-101)
I20260812 06:18:57.156473  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000021 (ops 102-106)
I20260812 06:18:57.156509  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000022 (ops 107-111)
I20260812 06:18:57.156554  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000023 (ops 112-116)
I20260812 06:18:57.156592  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000024 (ops 117-120)
I20260812 06:18:57.156628  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000025 (ops 121-125)
I20260812 06:18:57.156665  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000026 (ops 126-130)
I20260812 06:18:57.156700  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000027 (ops 131-134)
I20260812 06:18:57.182717  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:57.183176  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): 492 bytes on disk
I20260812 06:18:57.183781  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.184383  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=4.173312
I20260812 06:18:57.202983  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6153870,"delete_count":0,"lbm_write_time_us":7690,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:18:57.203434  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.211278  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2051402,"delete_count":0,"lbm_write_time_us":2747,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:18:57.211714  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.419652  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.208s	user 0.136s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":211,"lbm_read_time_us":12549,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35020,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":58752,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:18:57.420224  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=18.063937
I20260812 06:18:57.485352  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.065s	user 0.046s	sys 0.019s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":24512,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:57.485924  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:57.495891  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.496400  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.679848  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.183s	user 0.139s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918094,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":14398,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30082,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:18:57.680397  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:57.723425  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":18973,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.723888  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:57.740132  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.740873  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:57.901628  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.160s	user 0.129s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":762,"lbm_read_time_us":12017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27167,"lbm_writes_lt_1ms":543,"mutex_wait_us":15,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:18:57.902163  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:57.956709  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.054s	user 0.014s	sys 0.033s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.957221  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:57.967195  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.967696  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:58.126907  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.159s	user 0.114s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1054,"lbm_read_time_us":11519,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25900,"lbm_writes_lt_1ms":543,"mutex_wait_us":264,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:58.127385  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=11.118625
I20260812 06:18:58.172236  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.045s	user 0.007s	sys 0.030s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15978,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:58.172875  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:58.194190  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.194633  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:58.204345  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.204756  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:58.376848  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.172s	user 0.107s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":703,"lbm_read_time_us":12575,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31560,"lbm_writes_lt_1ms":543,"mutex_wait_us":340,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:18:58.377492  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:58.428728  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.051s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22744,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:58.429370  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:58.442139  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4513,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.449013  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:58.475744  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushMRSOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.027s	user 0.014s	sys 0.010s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1341,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1278,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:58.476490  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): free 108535692 bytes of WAL
I20260812 06:18:58.476722  7134 log_reader.cc:385] T 3b30d6a387314bb0a5d6639ce26ce0cc: removed 11 log segments from log reader
I20260812 06:18:58.476769  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000028 (ops 135-139)
I20260812 06:18:58.476824  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000029 (ops 140-144)
I20260812 06:18:58.476855  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000030 (ops 145-148)
I20260812 06:18:58.476889  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000031 (ops 149-153)
I20260812 06:18:58.476919  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000032 (ops 154-158)
I20260812 06:18:58.476949  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000033 (ops 159-163)
I20260812 06:18:58.476979  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000034 (ops 164-168)
I20260812 06:18:58.477010  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000035 (ops 169-173)
I20260812 06:18:58.477038  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000036 (ops 174-178)
I20260812 06:18:58.477068  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000037 (ops 179-182)
I20260812 06:18:58.477154  7134 log.cc:1079] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/3b30d6a387314bb0a5d6639ce26ce0cc/wal-000000038 (ops 183-187)
I20260812 06:18:58.496130  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: LogGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.019s	user 0.001s	sys 0.015s Metrics: {}
I20260812 06:18:58.496598  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=3.181125
I20260812 06:18:58.520350  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:58.520804  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=2.188937
I20260812 06:18:58.529599  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3171,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.530128  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc): 449 bytes on disk
I20260812 06:18:58.530581  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: UndoDeltaBlockGCOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.531359  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:58.710078  6954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.541s	user 1.614s	sys 0.152s
I20260812 06:18:58.731195  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.200s	user 0.137s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14848,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33918,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3500}
I20260812 06:18:58.731693  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=14.095187
I20260812 06:18:58.761960  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: FlushDeltaMemStoresOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.030s	user 0.021s	sys 0.009s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":14116,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:58.762394  7230 maintenance_manager.cc:419] P ec200ef010994d57b7b08caa60f4a731: Scheduling MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc): perf score=1.000000
I20260812 06:18:58.826633  6954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.116s	user 0.004s	sys 0.003s
I20260812 06:18:58.828684  6954 tablet_server.cc:179] TabletServer@127.6.202.129:0 shutting down...
I20260812 06:18:58.886246  7134 maintenance_manager.cc:643] P ec200ef010994d57b7b08caa60f4a731: MajorDeltaCompactionOp(3b30d6a387314bb0a5d6639ce26ce0cc) complete. Timing: real 0.124s	user 0.109s	sys 0.014s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":361,"lbm_read_time_us":8519,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24377,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:58.886883  6954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:58.887303  6954 tablet_replica.cc:333] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731: stopping tablet replica
I20260812 06:18:58.887522  6954 raft_consensus.cc:2243] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.887730  6954 raft_consensus.cc:2272] T 3b30d6a387314bb0a5d6639ce26ce0cc P ec200ef010994d57b7b08caa60f4a731 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.903240  6954 tablet_server.cc:196] TabletServer@127.6.202.129:0 shutdown complete.
I20260812 06:18:58.934393  6954 master.cc:562] Master@127.6.202.190:42085 shutting down...
I20260812 06:18:58.937646  6954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.937813  6954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.937889  6954 tablet_replica.cc:333] T 00000000000000000000000000000000 P b78ed904d2684fc5a049fba1fb85de5f: stopping tablet replica
I20260812 06:18:58.949832  6954 master.cc:584] Master@127.6.202.190:42085 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5121 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:59.022742  6954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.202.190:34059
I20260812 06:18:59.023109  6954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.024917  7282 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:59.024989  7280 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:59.024984  7284 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.025075  6954 server_base.cc:1061] running on GCE node
I20260812 06:18:59.025471  6954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.025516  6954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:59.025549  6954 hybrid_clock.cc:648] HybridClock initialized: now 1786515539025549 us; error 0 us; skew 500 ppm
I20260812 06:18:59.026371  6954 webserver.cc:533] Webserver started at http://127.6.202.190:40913/ using document root <none> and password file <none>
I20260812 06:18:59.026520  6954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.026569  6954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.026643  6954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.026998  6954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/master-0-root/instance:
uuid: "00ed40dbc49d47b8a2f701179a5a1134"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-266d"
I20260812 06:18:59.028414  6954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:59.029290  7295 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.029529  6954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:59.029597  6954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/master-0-root
uuid: "00ed40dbc49d47b8a2f701179a5a1134"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-266d"
I20260812 06:18:59.029652  6954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:59.047478  6954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.047816  6954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.051754  6954 rpc_server.cc:307] RPC server started. Bound to: 127.6.202.190:34059
I20260812 06:18:59.066378  7394 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.202.190:34059 every 8 connection(s)
I20260812 06:18:59.066845  7395 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:59.068638  7395 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: Bootstrap starting.
I20260812 06:18:59.069456  7395 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.070394  7395 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: No bootstrap required, opened a new log
I20260812 06:18:59.070767  7395 raft_consensus.cc:359] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER }
I20260812 06:18:59.070865  7395 raft_consensus.cc:385] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.070895  7395 raft_consensus.cc:740] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 00ed40dbc49d47b8a2f701179a5a1134, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.071034  7395 consensus_queue.cc:260] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [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: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER }
I20260812 06:18:59.071107  7395 raft_consensus.cc:399] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.071144  7395 raft_consensus.cc:493] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.071192  7395 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.071846  7395 raft_consensus.cc:515] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER }
I20260812 06:18:59.071979  7395 leader_election.cc:304] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [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: 00ed40dbc49d47b8a2f701179a5a1134; no voters: 
I20260812 06:18:59.072150  7395 leader_election.cc:290] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.072242  7399 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.072458  7399 raft_consensus.cc:697] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 1 LEADER]: Becoming Leader. State: Replica: 00ed40dbc49d47b8a2f701179a5a1134, State: Running, Role: LEADER
I20260812 06:18:59.072558  7395 sys_catalog.cc:565] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:59.072592  7399 consensus_queue.cc:237] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [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: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER }
I20260812 06:18:59.073016  7400 sys_catalog.cc:455] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "00ed40dbc49d47b8a2f701179a5a1134" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER } }
I20260812 06:18:59.073041  7401 sys_catalog.cc:455] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 00ed40dbc49d47b8a2f701179a5a1134. Latest consensus state: current_term: 1 leader_uuid: "00ed40dbc49d47b8a2f701179a5a1134" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "00ed40dbc49d47b8a2f701179a5a1134" member_type: VOTER } }
I20260812 06:18:59.073194  7401 sys_catalog.cc:458] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.073648  7400 sys_catalog.cc:458] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.074378  6954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:59.074810  7428 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:59.074865  7428 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:59.074934  7408 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:59.075481  7408 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:59.077319  7408 catalog_manager.cc:1383] Generated new cluster ID: 291c6fd3ad9a4a1697bfb98bd407c3b4
I20260812 06:18:59.077378  7408 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:59.092957  7408 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:59.093487  7408 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:59.099329  7408 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: Generated new TSK 0
I20260812 06:18:59.099472  7408 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:59.106383  6954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.108067  7435 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:59.108085  7433 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.108080  6954 server_base.cc:1061] running on GCE node
W20260812 06:18:59.108181  7438 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.108513  6954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.108556  6954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:59.108577  6954 hybrid_clock.cc:648] HybridClock initialized: now 1786515539108577 us; error 0 us; skew 500 ppm
I20260812 06:18:59.109372  6954 webserver.cc:533] Webserver started at http://127.6.202.129:43461/ using document root <none> and password file <none>
I20260812 06:18:59.109517  6954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.109565  6954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.109640  6954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.109982  6954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/instance:
uuid: "09d470c4944642e3b529421e8ed9e3c6"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-266d"
I20260812 06:18:59.111320  6954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:59.112124  7446 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.112329  6954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:59.112393  6954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root
uuid: "09d470c4944642e3b529421e8ed9e3c6"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-266d"
I20260812 06:18:59.112453  6954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:59.125159  6954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.125434  6954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.125677  6954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:59.126081  6954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:59.126117  6954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.126157  6954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:59.126183  6954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.130264  6954 rpc_server.cc:307] RPC server started. Bound to: 127.6.202.129:41317
I20260812 06:18:59.130295  7549 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.202.129:41317 every 8 connection(s)
I20260812 06:18:59.138988  7550 heartbeater.cc:344] Connected to a master server at 127.6.202.190:34059
I20260812 06:18:59.139075  7550 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:59.139242  7550 heartbeater.cc:507] Master 127.6.202.190:34059 requested a full tablet report, sending...
I20260812 06:18:59.139791  7333 ts_manager.cc:194] Registered new tserver with Master: 09d470c4944642e3b529421e8ed9e3c6 (127.6.202.129:41317)
I20260812 06:18:59.140450  7333 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59652
I20260812 06:18:59.140456  6954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009846326s
I20260812 06:18:59.146979  7333 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59668:
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:18:59.154721  7486 tablet_service.cc:1511] Processing CreateTablet for tablet db84dbe6b9564f9a8b70383ceefc7890 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f920b9c3a2b045dcbac15728bf21eec9]), partition=
I20260812 06:18:59.154947  7486 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet db84dbe6b9564f9a8b70383ceefc7890. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:59.156911  7572 tablet_bootstrap.cc:492] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Bootstrap starting.
I20260812 06:18:59.157796  7572 tablet_bootstrap.cc:654] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.158699  7572 tablet_bootstrap.cc:492] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: No bootstrap required, opened a new log
I20260812 06:18:59.158769  7572 ts_tablet_manager.cc:1403] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:59.159116  7572 raft_consensus.cc:359] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "09d470c4944642e3b529421e8ed9e3c6" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 41317 } }
I20260812 06:18:59.159194  7572 raft_consensus.cc:385] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.159215  7572 raft_consensus.cc:740] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 09d470c4944642e3b529421e8ed9e3c6, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.159361  7572 consensus_queue.cc:260] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [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: "09d470c4944642e3b529421e8ed9e3c6" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 41317 } }
I20260812 06:18:59.159461  7572 raft_consensus.cc:399] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.159507  7572 raft_consensus.cc:493] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.159556  7572 raft_consensus.cc:3060] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.160336  7572 raft_consensus.cc:515] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "09d470c4944642e3b529421e8ed9e3c6" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 41317 } }
I20260812 06:18:59.160456  7572 leader_election.cc:304] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [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: 09d470c4944642e3b529421e8ed9e3c6; no voters: 
I20260812 06:18:59.160634  7572 leader_election.cc:290] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.160742  7575 raft_consensus.cc:2804] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.160912  7575 raft_consensus.cc:697] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 1 LEADER]: Becoming Leader. State: Replica: 09d470c4944642e3b529421e8ed9e3c6, State: Running, Role: LEADER
I20260812 06:18:59.160933  7550 heartbeater.cc:499] Master 127.6.202.190:34059 was elected leader, sending a full tablet report...
I20260812 06:18:59.160928  7572 ts_tablet_manager.cc:1434] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:59.161111  7575 consensus_queue.cc:237] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [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: "09d470c4944642e3b529421e8ed9e3c6" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 41317 } }
I20260812 06:18:59.162328  7333 catalog_manager.cc:5719] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 09d470c4944642e3b529421e8ed9e3c6 (127.6.202.129). New cstate: current_term: 1 leader_uuid: "09d470c4944642e3b529421e8ed9e3c6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "09d470c4944642e3b529421e8ed9e3c6" member_type: VOTER last_known_addr { host: "127.6.202.129" port: 41317 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:59.216046  6954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.009s	sys 0.012s
I20260812 06:18:59.381299  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=23.023690
I20260812 06:18:59.533010  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.151s	user 0.099s	sys 0.048s Metrics: {"bytes_written":13579241,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":964,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40369,"lbm_writes_lt_1ms":888,"mutex_wait_us":925,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":17152,"update_count":1655}
I20260812 06:18:59.533695  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling LogGCOp(db84dbe6b9564f9a8b70383ceefc7890): free 20743880 bytes of WAL
I20260812 06:18:59.533955  7452 log_reader.cc:385] T db84dbe6b9564f9a8b70383ceefc7890: removed 2 log segments from log reader
I20260812 06:18:59.534011  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000001 (ops 1-6)
I20260812 06:18:59.534049  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000002 (ops 7-11)
I20260812 06:18:59.537730  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: LogGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:59.538074  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:18:59.548264  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4061638,"delete_count":0,"lbm_write_time_us":3709,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:18:59.548595  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.196750
I20260812 06:18:59.558655  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3670,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:18:59.559000  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890): 20513813 bytes on disk
I20260812 06:18:59.559382  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:59.559731  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:18:59.726898  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.167s	user 0.092s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815779,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":780,"lbm_read_time_us":11294,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26257,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":324,"threads_started":5,"update_count":2500}
I20260812 06:18:59.727389  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=14.095187
I20260812 06:18:59.785471  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.058s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.785946  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:18:59.795482  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.795854  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:18:59.965694  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.170s	user 0.125s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":11318,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26677,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:59.966291  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=11.118625
I20260812 06:18:59.995213  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11733,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:59.995818  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:00.007228  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:00.007682  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:00.141207  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.133s	user 0.083s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":7346,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23882,"lbm_writes_lt_1ms":443,"mutex_wait_us":112,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.141872  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=11.118625
I20260812 06:19:00.175112  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.033s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14018,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:00.175729  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:00.189922  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4892,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:00.190718  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:00.302801  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.112s	user 0.097s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1131,"lbm_read_time_us":6869,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21478,"lbm_writes_lt_1ms":443,"mutex_wait_us":576,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:19:00.303522  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=10.126437
I20260812 06:19:00.341408  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16076,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.342098  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:00.356096  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.356534  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:00.477442  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.121s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":635,"lbm_read_time_us":8221,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22983,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:19:00.477895  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=10.126437
I20260812 06:19:00.527197  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.049s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12215,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.527709  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:00.544149  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.544595  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:00.694602  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.150s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":449,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24093,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:19:00.695307  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=10.126437
I20260812 06:19:00.732368  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.037s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16202,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.732887  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:00.745685  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.746232  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:00.771967  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.026s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1291,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1400,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:00.772604  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling LogGCOp(db84dbe6b9564f9a8b70383ceefc7890): free 121006434 bytes of WAL
I20260812 06:19:00.772881  7452 log_reader.cc:385] T db84dbe6b9564f9a8b70383ceefc7890: removed 12 log segments from log reader
I20260812 06:19:00.772981  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000003 (ops 12-16)
I20260812 06:19:00.773041  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000004 (ops 17-21)
I20260812 06:19:00.773074  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000005 (ops 22-26)
I20260812 06:19:00.773136  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000006 (ops 27-31)
I20260812 06:19:00.773175  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000007 (ops 32-36)
I20260812 06:19:00.773211  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000008 (ops 37-41)
I20260812 06:19:00.773247  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000009 (ops 42-46)
I20260812 06:19:00.773284  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000010 (ops 47-51)
I20260812 06:19:00.773319  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000011 (ops 52-56)
I20260812 06:19:00.773355  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000012 (ops 57-60)
I20260812 06:19:00.773396  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000013 (ops 61-65)
I20260812 06:19:00.773432  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000014 (ops 66-70)
I20260812 06:19:00.796097  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: LogGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:00.796557  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890): 473 bytes on disk
I20260812 06:19:00.796979  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.797494  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=4.173312
I20260812 06:19:00.811172  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:19:00.811573  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.196750
I20260812 06:19:00.828342  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3681,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:00.828835  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:01.042032  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.213s	user 0.142s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918305,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":178,"lbm_read_time_us":13835,"lbm_reads_lt_1ms":666,"lbm_write_time_us":33696,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:01.042667  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=18.063937
I20260812 06:19:01.112267  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.069s	user 0.045s	sys 0.008s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":31103,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:01.112731  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=3.181125
I20260812 06:19:01.135120  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4471876,"delete_count":0,"lbm_write_time_us":5523,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:19:01.135582  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:01.144320  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3254,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:19:01.144735  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:01.366958  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.222s	user 0.154s	sys 0.067s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":221,"lbm_read_time_us":14238,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39702,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":3500}
I20260812 06:19:01.367481  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=18.063937
I20260812 06:19:01.416781  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.049s	user 0.023s	sys 0.019s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":20597,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:01.417449  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:01.593256  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.176s	user 0.091s	sys 0.077s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815571,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":673,"lbm_read_time_us":12103,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28361,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:01.593760  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=15.087375
I20260812 06:19:01.651728  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.058s	user 0.019s	sys 0.021s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":18235,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:01.652169  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=6.157687
I20260812 06:19:01.672592  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.020s	user 0.011s	sys 0.007s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8469,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:01.673141  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:01.878562  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.205s	user 0.112s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":12282,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32850,"lbm_writes_lt_1ms":643,"mutex_wait_us":70,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:01.879133  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=18.063937
I20260812 06:19:01.937669  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.058s	user 0.051s	sys 0.000s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":22467,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:01.938149  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:01.952999  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.953542  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:02.149597  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.196s	user 0.123s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":12306,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31163,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:02.150151  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=16.079562
I20260812 06:19:02.202119  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.052s	user 0.036s	sys 0.013s Metrics: {"bytes_written":17804726,"delete_count":0,"lbm_write_time_us":22263,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:19:02.202672  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.196750
I20260812 06:19:02.222600  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.020s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:19:02.223013  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:02.231611  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3220,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:02.231982  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:02.264695  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":151,"dirs.run_wall_time_us":1086,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2016,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":3840}
I20260812 06:19:02.265393  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling LogGCOp(db84dbe6b9564f9a8b70383ceefc7890): free 132571286 bytes of WAL
I20260812 06:19:02.265614  7452 log_reader.cc:385] T db84dbe6b9564f9a8b70383ceefc7890: removed 13 log segments from log reader
I20260812 06:19:02.265661  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000015 (ops 71-75)
I20260812 06:19:02.265691  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000016 (ops 76-80)
I20260812 06:19:02.265724  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000017 (ops 81-85)
I20260812 06:19:02.265758  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000018 (ops 86-90)
I20260812 06:19:02.265789  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000019 (ops 91-94)
I20260812 06:19:02.265821  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000020 (ops 95-99)
I20260812 06:19:02.265854  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000021 (ops 100-104)
I20260812 06:19:02.265887  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000022 (ops 105-109)
I20260812 06:19:02.265918  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000023 (ops 110-114)
I20260812 06:19:02.265951  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000024 (ops 115-119)
I20260812 06:19:02.265983  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000025 (ops 120-124)
I20260812 06:19:02.266016  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000026 (ops 125-128)
I20260812 06:19:02.266047  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000027 (ops 129-133)
I20260812 06:19:02.287477  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: LogGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.022s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:02.287894  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:02.308888  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.021s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.309294  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling LogGCOp(db84dbe6b9564f9a8b70383ceefc7890): free 12018013 bytes of WAL
I20260812 06:19:02.309475  7452 log_reader.cc:385] T db84dbe6b9564f9a8b70383ceefc7890: removed 1 log segments from log reader
I20260812 06:19:02.309520  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000028 (ops 134-138)
I20260812 06:19:02.311424  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: LogGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:02.311697  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890): 492 bytes on disk
I20260812 06:19:02.312037  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: UndoDeltaBlockGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:02.312479  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:02.323150  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.324124  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:02.542574  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.218s	user 0.148s	sys 0.068s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123246,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":356,"lbm_read_time_us":17069,"lbm_reads_lt_1ms":867,"lbm_write_time_us":37429,"lbm_writes_lt_1ms":843,"mutex_wait_us":24,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":71,"threads_started":1,"update_count":4000}
I20260812 06:19:02.543217  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=19.056125
I20260812 06:19:02.601500  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.058s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20922556,"delete_count":0,"lbm_write_time_us":22670,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:19:02.602046  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=6.157687
I20260812 06:19:02.626624  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.024s	user 0.019s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10085,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:02.627094  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:02.814559  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.187s	user 0.138s	sys 0.044s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020509,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":12128,"lbm_reads_lt_1ms":772,"lbm_write_time_us":36842,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":3500}
I20260812 06:19:02.815157  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=18.063937
I20260812 06:19:02.873354  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.058s	user 0.051s	sys 0.007s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25518,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.873950  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:02.885560  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.886024  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:03.051185  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.165s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":11127,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33887,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:03.051702  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=14.095187
I20260812 06:19:03.092389  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17815,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.092959  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:03.103196  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.103740  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:03.263008  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.159s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":9510,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26994,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:03.263620  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=14.095187
I20260812 06:19:03.313688  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.050s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.314201  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:03.458871  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.144s	user 0.088s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":215,"lbm_read_time_us":8625,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23219,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:19:03.459347  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=14.095187
I20260812 06:19:03.505465  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.046s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16048,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.506006  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:03.521502  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.522099  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:03.558945  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushMRSOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.037s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1220,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1505,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:03.559692  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling LogGCOp(db84dbe6b9564f9a8b70383ceefc7890): free 108988743 bytes of WAL
I20260812 06:19:03.559926  7452 log_reader.cc:385] T db84dbe6b9564f9a8b70383ceefc7890: removed 11 log segments from log reader
I20260812 06:19:03.559978  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000029 (ops 139-143)
I20260812 06:19:03.560011  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000030 (ops 144-148)
I20260812 06:19:03.560060  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000031 (ops 149-152)
I20260812 06:19:03.560099  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000032 (ops 153-157)
I20260812 06:19:03.560138  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000033 (ops 158-162)
I20260812 06:19:03.560176  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000034 (ops 163-167)
I20260812 06:19:03.560213  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000035 (ops 168-172)
I20260812 06:19:03.560250  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000036 (ops 173-177)
I20260812 06:19:03.560287  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000037 (ops 178-182)
I20260812 06:19:03.560326  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000038 (ops 183-187)
I20260812 06:19:03.560364  7452 log.cc:1079] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: Deleting log segment in path: /tmp/dist-test-taskWOqPJP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533890710-6954-0/minicluster-data/ts-0-root/wals/db84dbe6b9564f9a8b70383ceefc7890/wal-000000039 (ops 188-192)
I20260812 06:19:03.579579  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: LogGCOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:03.580003  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:03.605876  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.026s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.606323  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=2.188937
I20260812 06:19:03.617369  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: FlushDeltaMemStoresOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.618391  7554 maintenance_manager.cc:419] P 09d470c4944642e3b529421e8ed9e3c6: Scheduling MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890): perf score=1.000000
I20260812 06:19:03.713306  6954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.497s	user 1.664s	sys 0.156s
I20260812 06:19:03.806165  6954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.001s	sys 0.000s
I20260812 06:19:03.806624  6954 tablet_server.cc:179] TabletServer@127.6.202.129:0 shutting down...
I20260812 06:19:03.834314  7452 maintenance_manager.cc:643] P 09d470c4944642e3b529421e8ed9e3c6: MajorDeltaCompactionOp(db84dbe6b9564f9a8b70383ceefc7890) complete. Timing: real 0.216s	user 0.131s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":419,"lbm_read_time_us":17979,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34048,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":82688,"thread_start_us":68,"threads_started":1,"update_count":3500}
I20260812 06:19:03.834854  6954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:03.835193  6954 tablet_replica.cc:333] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6: stopping tablet replica
I20260812 06:19:03.835376  6954 raft_consensus.cc:2243] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.835538  6954 raft_consensus.cc:2272] T db84dbe6b9564f9a8b70383ceefc7890 P 09d470c4944642e3b529421e8ed9e3c6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.851943  6954 tablet_server.cc:196] TabletServer@127.6.202.129:0 shutdown complete.
I20260812 06:19:03.889909  6954 master.cc:562] Master@127.6.202.190:34059 shutting down...
I20260812 06:19:03.892896  6954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.893065  6954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.893160  6954 tablet_replica.cc:333] T 00000000000000000000000000000000 P 00ed40dbc49d47b8a2f701179a5a1134: stopping tablet replica
I20260812 06:19:03.905236  6954 master.cc:584] Master@127.6.202.190:34059 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4951 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10074 ms total)

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