[==========] 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:16:24.046865   564 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.141.62:43365
I20260812 06:16:24.048081   564 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:16:24.048777   564 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:24.060289   564 server_base.cc:1061] running on GCE node
W20260812 06:16:24.060329   570 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:16:24.060302   572 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:16:24.060817   569 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:16:24.061580   564 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:24.061798   564 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:16:24.061833   564 hybrid_clock.cc:648] HybridClock initialized: now 1786515384061831 us; error 0 us; skew 500 ppm
I20260812 06:16:24.064344   564 webserver.cc:533] Webserver started at http://127.0.141.62:43327/ using document root <none> and password file <none>
I20260812 06:16:24.064965   564 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:24.065037   564 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:24.065313   564 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:24.067340   564 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/master-0-root/instance:
uuid: "ad486d7f39d74b53b00209e51d848998"
format_stamp: "Formatted at 2026-08-12 06:16:24 on dist-test-slave-g350"
I20260812 06:16:24.072854   564 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.006s	sys 0.000s
I20260812 06:16:24.076210   577 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:16:24.077772   564 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:24.077955   564 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/master-0-root
uuid: "ad486d7f39d74b53b00209e51d848998"
format_stamp: "Formatted at 2026-08-12 06:16:24 on dist-test-slave-g350"
I20260812 06:16:24.078096   564 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-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:16:24.114969   564 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:24.115713   564 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:16:24.115952   564 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:24.124822   564 rpc_server.cc:307] RPC server started. Bound to: 127.0.141.62:43365
I20260812 06:16:24.124894   634 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.141.62:43365 every 8 connection(s)
I20260812 06:16:24.127627   635 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:16:24.134366   635 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: Bootstrap starting.
I20260812 06:16:24.137188   635 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:24.138413   635 log.cc:826] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:24.140743   635 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: No bootstrap required, opened a new log
I20260812 06:16:24.143949   635 raft_consensus.cc:359] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER }
I20260812 06:16:24.144186   635 raft_consensus.cc:385] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:24.144245   635 raft_consensus.cc:740] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ad486d7f39d74b53b00209e51d848998, State: Initialized, Role: FOLLOWER
I20260812 06:16:24.144969   635 consensus_queue.cc:260] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [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: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER }
I20260812 06:16:24.145152   635 raft_consensus.cc:399] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:24.145263   635 raft_consensus.cc:493] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:24.145401   635 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:24.146448   635 raft_consensus.cc:515] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER }
I20260812 06:16:24.146992   635 leader_election.cc:304] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [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: ad486d7f39d74b53b00209e51d848998; no voters: 
I20260812 06:16:24.147428   635 leader_election.cc:290] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:24.147671   638 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:24.147982   638 raft_consensus.cc:697] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 1 LEADER]: Becoming Leader. State: Replica: ad486d7f39d74b53b00209e51d848998, State: Running, Role: LEADER
I20260812 06:16:24.148427   638 consensus_queue.cc:237] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [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: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER }
I20260812 06:16:24.148655   635 sys_catalog.cc:565] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:24.150935   642 sys_catalog.cc:455] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ad486d7f39d74b53b00209e51d848998. Latest consensus state: current_term: 1 leader_uuid: "ad486d7f39d74b53b00209e51d848998" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER } }
I20260812 06:16:24.151129   642 sys_catalog.cc:458] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:24.150903   640 sys_catalog.cc:455] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ad486d7f39d74b53b00209e51d848998" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad486d7f39d74b53b00209e51d848998" member_type: VOTER } }
I20260812 06:16:24.151371   640 sys_catalog.cc:458] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:24.151611   655 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:24.151755   564 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:24.154453   655 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:24.160877   655 catalog_manager.cc:1383] Generated new cluster ID: 9cb2d583d89f46f8abbd4e692d6d1a94
I20260812 06:16:24.160981   655 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:24.170579   655 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:24.172088   655 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:24.192708   655 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: Generated new TSK 0
I20260812 06:16:24.193581   655 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:24.218511   564 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:24.221863   665 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:16:24.221977   564 server_base.cc:1061] running on GCE node
W20260812 06:16:24.221839   662 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:16:24.221781   663 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:16:24.222402   564 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:24.222455   564 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:16:24.222539   564 hybrid_clock.cc:648] HybridClock initialized: now 1786515384222538 us; error 0 us; skew 500 ppm
I20260812 06:16:24.223672   564 webserver.cc:533] Webserver started at http://127.0.141.1:43609/ using document root <none> and password file <none>
I20260812 06:16:24.223898   564 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:24.223959   564 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:24.224073   564 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:24.224506   564 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/instance:
uuid: "340f5ec149ab461f86b3cc7d8c75a3d1"
format_stamp: "Formatted at 2026-08-12 06:16:24 on dist-test-slave-g350"
I20260812 06:16:24.226364   564 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:24.228001   672 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:16:24.228485   564 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:24.228582   564 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root
uuid: "340f5ec149ab461f86b3cc7d8c75a3d1"
format_stamp: "Formatted at 2026-08-12 06:16:24 on dist-test-slave-g350"
I20260812 06:16:24.228844   564 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-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:16:24.242143   564 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:24.242661   564 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:24.243256   564 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:24.244225   564 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:24.244284   564 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:24.244359   564 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:24.244408   564 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:24.252142   564 rpc_server.cc:307] RPC server started. Bound to: 127.0.141.1:41085
I20260812 06:16:24.252195   742 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.141.1:41085 every 8 connection(s)
I20260812 06:16:24.269012   744 heartbeater.cc:344] Connected to a master server at 127.0.141.62:43365
I20260812 06:16:24.269368   744 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:24.269965   744 heartbeater.cc:507] Master 127.0.141.62:43365 requested a full tablet report, sending...
I20260812 06:16:24.271667   595 ts_manager.cc:194] Registered new tserver with Master: 340f5ec149ab461f86b3cc7d8c75a3d1 (127.0.141.1:41085)
I20260812 06:16:24.272430   564 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019556908s
I20260812 06:16:24.273481   595 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59146
I20260812 06:16:24.284876   595 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59150:
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:16:24.304582   702 tablet_service.cc:1511] Processing CreateTablet for tablet bdfc5b2bb81145f4b8cccf1c0b0cb613 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fd1c307c428243719c99656cbe24c471]), partition=
I20260812 06:16:24.305313   702 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bdfc5b2bb81145f4b8cccf1c0b0cb613. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:24.309763   758 tablet_bootstrap.cc:492] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Bootstrap starting.
I20260812 06:16:24.310981   758 tablet_bootstrap.cc:654] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:24.312638   758 tablet_bootstrap.cc:492] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: No bootstrap required, opened a new log
I20260812 06:16:24.312799   758 ts_tablet_manager.cc:1403] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:24.313305   758 raft_consensus.cc:359] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "340f5ec149ab461f86b3cc7d8c75a3d1" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 41085 } }
I20260812 06:16:24.313447   758 raft_consensus.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:24.313496   758 raft_consensus.cc:740] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 340f5ec149ab461f86b3cc7d8c75a3d1, State: Initialized, Role: FOLLOWER
I20260812 06:16:24.313678   758 consensus_queue.cc:260] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [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: "340f5ec149ab461f86b3cc7d8c75a3d1" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 41085 } }
I20260812 06:16:24.313819   758 raft_consensus.cc:399] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:24.313875   758 raft_consensus.cc:493] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:24.313933   758 raft_consensus.cc:3060] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:24.314792   758 raft_consensus.cc:515] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "340f5ec149ab461f86b3cc7d8c75a3d1" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 41085 } }
I20260812 06:16:24.314978   758 leader_election.cc:304] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [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: 340f5ec149ab461f86b3cc7d8c75a3d1; no voters: 
I20260812 06:16:24.315261   758 leader_election.cc:290] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:24.315573   760 raft_consensus.cc:2804] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:24.315786   758 ts_tablet_manager.cc:1434] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:24.315948   760 raft_consensus.cc:697] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 1 LEADER]: Becoming Leader. State: Replica: 340f5ec149ab461f86b3cc7d8c75a3d1, State: Running, Role: LEADER
I20260812 06:16:24.316167   760 consensus_queue.cc:237] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [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: "340f5ec149ab461f86b3cc7d8c75a3d1" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 41085 } }
I20260812 06:16:24.316361   744 heartbeater.cc:499] Master 127.0.141.62:43365 was elected leader, sending a full tablet report...
I20260812 06:16:24.319662   595 catalog_manager.cc:5719] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 340f5ec149ab461f86b3cc7d8c75a3d1 (127.0.141.1). New cstate: current_term: 1 leader_uuid: "340f5ec149ab461f86b3cc7d8c75a3d1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "340f5ec149ab461f86b3cc7d8c75a3d1" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 41085 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:24.397082   564 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.071s	user 0.024s	sys 0.012s
I20260812 06:16:24.503844   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=11.117440
I20260812 06:16:24.677203   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.173s	user 0.121s	sys 0.047s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":586,"delete_count":0,"dirs.queue_time_us":141,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1001,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48206,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":1408,"thread_start_us":221,"threads_started":1,"update_count":1000}
I20260812 06:16:24.678411   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): free 8725963 bytes of WAL
I20260812 06:16:24.678782   677 log_reader.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613: removed 1 log segments from log reader
I20260812 06:16:24.678866   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000001 (ops 1-6)
I20260812 06:16:24.680755   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:24.681205   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): 12308960 bytes on disk
I20260812 06:16:24.682077   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:16:24.682606   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:24.697283   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5420,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.697845   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:24.820101   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.122s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":6445,"lbm_reads_lt_1ms":360,"lbm_write_time_us":24555,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":352,"threads_started":5,"update_count":1500}
I20260812 06:16:24.821221   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=6.157687
I20260812 06:16:24.869422   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.048s	user 0.027s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":15019,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":1000}
I20260812 06:16:24.870108   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:24.887594   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.888406   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:25.018520   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.130s	user 0.103s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1190,"lbm_read_time_us":7102,"lbm_reads_lt_1ms":372,"lbm_write_time_us":24599,"lbm_writes_lt_1ms":343,"mutex_wait_us":54,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":1500}
I20260812 06:16:25.019492   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:25.073520   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.054s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20786,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.074205   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:25.086027   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.086660   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:25.232033   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.145s	user 0.110s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":417,"lbm_read_time_us":9789,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30915,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:25.232681   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:25.278853   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.046s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20550,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.279574   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:25.294034   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.294543   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:25.422194   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.127s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":8338,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28245,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:16:25.422786   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:25.468739   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.046s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18287,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.469250   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:25.480369   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.480964   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:25.622080   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.141s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":492,"lbm_read_time_us":7895,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29798,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:25.622881   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:25.694504   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.071s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":30647,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.695175   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:25.706760   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.707274   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:25.892971   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.186s	user 0.115s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1026,"lbm_read_time_us":11997,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32019,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":94848,"update_count":2000}
I20260812 06:16:25.893627   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:25.958768   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.065s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21096,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.959435   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:25.976905   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.979835   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:26.145325   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.165s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1768,"lbm_read_time_us":11403,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34442,"lbm_writes_lt_1ms":443,"mutex_wait_us":832,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:26.147032   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=11.118625
I20260812 06:16:26.198899   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.052s	user 0.047s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22757,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:26.199805   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:26.216584   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6203,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:26.217281   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:26.255414   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.038s	user 0.033s	sys 0.003s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":188,"dirs.run_cpu_time_us":343,"dirs.run_wall_time_us":1843,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2579,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:26.257083   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): free 132571301 bytes of WAL
I20260812 06:16:26.257469   677 log_reader.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613: removed 13 log segments from log reader
I20260812 06:16:26.257541   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000002 (ops 7-11)
I20260812 06:16:26.257642   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000003 (ops 12-16)
I20260812 06:16:26.257840   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000004 (ops 17-21)
I20260812 06:16:26.257917   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000005 (ops 22-26)
I20260812 06:16:26.257953   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000006 (ops 27-30)
I20260812 06:16:26.257972   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000007 (ops 31-35)
I20260812 06:16:26.257990   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000008 (ops 36-40)
I20260812 06:16:26.258008   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000009 (ops 41-45)
I20260812 06:16:26.258024   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000010 (ops 46-50)
I20260812 06:16:26.258041   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000011 (ops 51-55)
I20260812 06:16:26.258059   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000012 (ops 56-60)
I20260812 06:16:26.258091   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000013 (ops 61-64)
I20260812 06:16:26.258136   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000014 (ops 65-69)
I20260812 06:16:26.290028   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.033s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:16:26.290563   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): 482 bytes on disk
I20260812 06:16:26.291064   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:16:26.291550   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=6.157687
I20260812 06:16:26.330075   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.038s	user 0.020s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11033,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:26.330657   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:26.342147   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.342653   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:26.551378   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.209s	user 0.156s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938777,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":705,"lbm_read_time_us":15039,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43014,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":33152,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:16:26.555769   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=14.095187
I20260812 06:16:26.610692   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.054s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24724,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.611476   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:26.633123   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.021s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.633793   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:26.816215   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.182s	user 0.134s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733719,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":532,"lbm_read_time_us":12408,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28608,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:16:26.817286   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=14.095187
I20260812 06:16:26.868328   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.051s	user 0.012s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23271,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.868902   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:26.882228   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.882794   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:27.041177   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.158s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1421,"lbm_read_time_us":9791,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33108,"lbm_writes_lt_1ms":543,"mutex_wait_us":535,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:16:27.042025   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:27.085682   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.043s	user 0.012s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17809,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.086375   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.102032   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.102912   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:27.244117   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.141s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":11162,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28007,"lbm_writes_lt_1ms":443,"mutex_wait_us":98,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:16:27.245265   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:27.292781   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.046s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20623,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.293470   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.306878   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4558,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.307633   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:27.455961   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.148s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1123,"lbm_read_time_us":10136,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29790,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":58624,"update_count":2000}
I20260812 06:16:27.456826   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:27.516573   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.060s	user 0.012s	sys 0.037s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19681,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.517274   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.530341   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.531003   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:27.697713   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.167s	user 0.116s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":283,"lbm_read_time_us":13769,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26673,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:16:27.698607   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:27.744889   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.046s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18890,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.745654   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.765832   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.766491   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:27.800940   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.034s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":419,"dirs.run_wall_time_us":1946,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2195,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:27.801962   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): free 120100328 bytes of WAL
I20260812 06:16:27.802245   677 log_reader.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613: removed 12 log segments from log reader
I20260812 06:16:27.802299   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000015 (ops 70-74)
I20260812 06:16:27.802335   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000016 (ops 75-79)
I20260812 06:16:27.802418   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000017 (ops 80-84)
I20260812 06:16:27.802467   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000018 (ops 85-88)
I20260812 06:16:27.802523   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000019 (ops 89-93)
I20260812 06:16:27.802577   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000020 (ops 94-98)
I20260812 06:16:27.802641   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000021 (ops 99-102)
I20260812 06:16:27.802690   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000022 (ops 103-107)
I20260812 06:16:27.802738   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000023 (ops 108-112)
I20260812 06:16:27.802788   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000024 (ops 113-116)
I20260812 06:16:27.802834   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000025 (ops 117-121)
I20260812 06:16:27.802904   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000026 (ops 122-126)
I20260812 06:16:27.831796   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:27.832341   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): 448 bytes on disk
I20260812 06:16:27.832914   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.833552   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.850013   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.016s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.850510   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:27.872473   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.022s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.873036   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:28.083024   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.210s	user 0.134s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836376,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":938,"lbm_read_time_us":12992,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37775,"lbm_writes_lt_1ms":643,"mutex_wait_us":97,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25088,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:16:28.083959   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=14.095187
I20260812 06:16:28.156124   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.072s	user 0.050s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.157121   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:28.174811   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.175498   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:28.382767   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.207s	user 0.128s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":15932,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34967,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:16:28.385151   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=11.118625
I20260812 06:16:28.427045   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.041s	user 0.036s	sys 0.003s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17997,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:28.428020   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:28.449973   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.022s	user 0.019s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6353,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.450800   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:28.598413   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.147s	user 0.117s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1105,"lbm_read_time_us":9583,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27522,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:16:28.599138   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:28.653862   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.055s	user 0.026s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20896,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.654479   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:28.667935   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.668613   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:28.815819   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.147s	user 0.107s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1112,"lbm_read_time_us":8571,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31726,"lbm_writes_lt_1ms":443,"mutex_wait_us":415,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.816815   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:28.865152   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.048s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20620,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.866153   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:28.886504   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.020s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.887284   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.041857   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.154s	user 0.117s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":9114,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34540,"lbm_writes_lt_1ms":443,"mutex_wait_us":463,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:16:29.042676   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:29.094102   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.051s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20227,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:29.094923   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:29.107203   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.107784   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.273768   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.166s	user 0.116s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":13614,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28774,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2000}
I20260812 06:16:29.274551   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:29.329545   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.055s	user 0.017s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19596,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:29.330330   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:29.343482   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.344321   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.489085   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.145s	user 0.112s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":752,"lbm_read_time_us":10672,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30483,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:29.490190   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=10.126437
I20260812 06:16:29.538069   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.048s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20844,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":1500}
I20260812 06:16:29.538681   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:29.558856   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.020s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.559413   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.593286   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushMRSOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":119,"dirs.run_cpu_time_us":292,"dirs.run_wall_time_us":2041,"drs_written":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1607,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:29.594316   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): free 121006632 bytes of WAL
I20260812 06:16:29.594605   677 log_reader.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613: removed 12 log segments from log reader
I20260812 06:16:29.594653   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000027 (ops 127-131)
I20260812 06:16:29.594684   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000028 (ops 132-136)
I20260812 06:16:29.594764   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000029 (ops 137-141)
I20260812 06:16:29.594795   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000030 (ops 142-146)
I20260812 06:16:29.594837   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000031 (ops 147-151)
I20260812 06:16:29.594879   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000032 (ops 152-156)
I20260812 06:16:29.594919   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000033 (ops 157-161)
I20260812 06:16:29.594955   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000034 (ops 162-166)
I20260812 06:16:29.595012   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000035 (ops 167-170)
I20260812 06:16:29.595054   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000036 (ops 171-175)
I20260812 06:16:29.595095   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000037 (ops 176-180)
I20260812 06:16:29.595141   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000038 (ops 181-185)
I20260812 06:16:29.621702   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:29.622334   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): 482 bytes on disk
I20260812 06:16:29.622872   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: UndoDeltaBlockGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:29.623819   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=3.181125
I20260812 06:16:29.641544   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6922,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:29.642158   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): free 12018004 bytes of WAL
I20260812 06:16:29.642396   677 log_reader.cc:385] T bdfc5b2bb81145f4b8cccf1c0b0cb613: removed 1 log segments from log reader
I20260812 06:16:29.642441   677 log.cc:1079] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515384034829-564-0/minicluster-data/ts-0-root/wals/bdfc5b2bb81145f4b8cccf1c0b0cb613/wal-000000039 (ops 186-190)
I20260812 06:16:29.644752   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: LogGCOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:29.645155   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:29.662521   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6101,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.663687   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.856426   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.193s	user 0.142s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1694,"lbm_read_time_us":12473,"lbm_reads_lt_1ms":666,"lbm_write_time_us":37399,"lbm_writes_lt_1ms":643,"mutex_wait_us":101,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"thread_start_us":118,"threads_started":1,"update_count":3000}
I20260812 06:16:29.857829   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=14.095187
I20260812 06:16:29.915889   564 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.519s	user 2.053s	sys 0.124s
I20260812 06:16:29.919785   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.062s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24646,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.920526   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=2.188937
I20260812 06:16:29.937268   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: FlushDeltaMemStoresOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":500}
I20260812 06:16:29.938017   745 maintenance_manager.cc:419] P 340f5ec149ab461f86b3cc7d8c75a3d1: Scheduling MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613): perf score=1.000000
I20260812 06:16:29.978719   564 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.003s	sys 0.000s
I20260812 06:16:29.979532   564 tablet_server.cc:179] TabletServer@127.0.141.1:0 shutting down...
I20260812 06:16:30.080299   677 maintenance_manager.cc:643] P 340f5ec149ab461f86b3cc7d8c75a3d1: MajorDeltaCompactionOp(bdfc5b2bb81145f4b8cccf1c0b0cb613) complete. Timing: real 0.142s	user 0.117s	sys 0.025s Metrics: {"cfile_cache_hit":371,"cfile_cache_hit_bytes":15179439,"cfile_cache_miss":161,"cfile_cache_miss_bytes":9554286,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":478,"lbm_read_time_us":4906,"lbm_reads_lt_1ms":193,"lbm_write_time_us":31492,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:16:30.086144   564 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:30.086722   564 tablet_replica.cc:333] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1: stopping tablet replica
I20260812 06:16:30.087037   564 raft_consensus.cc:2243] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:30.087688   564 raft_consensus.cc:2272] T bdfc5b2bb81145f4b8cccf1c0b0cb613 P 340f5ec149ab461f86b3cc7d8c75a3d1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:30.107007   564 tablet_server.cc:196] TabletServer@127.0.141.1:0 shutdown complete.
I20260812 06:16:30.129757   564 master.cc:562] Master@127.0.141.62:43365 shutting down...
I20260812 06:16:30.134509   564 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:30.134718   564 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:30.134769   564 tablet_replica.cc:333] T 00000000000000000000000000000000 P ad486d7f39d74b53b00209e51d848998: stopping tablet replica
I20260812 06:16:30.148603   564 master.cc:584] Master@127.0.141.62:43365 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6198 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:30.244415   564 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.141.62:43319
I20260812 06:16:30.244904   564 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:30.247699   779 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:16:30.247886   778 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:16:30.247964   564 server_base.cc:1061] running on GCE node
W20260812 06:16:30.247975   781 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:16:30.248287   564 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:30.248346   564 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:16:30.248364   564 hybrid_clock.cc:648] HybridClock initialized: now 1786515390248365 us; error 0 us; skew 500 ppm
I20260812 06:16:30.249265   564 webserver.cc:533] Webserver started at http://127.0.141.62:34691/ using document root <none> and password file <none>
I20260812 06:16:30.249434   564 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:30.249477   564 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:30.249536   564 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:30.250391   564 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/master-0-root/instance:
uuid: "1df9715fb3d844a3bcf17843530cf326"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-g350"
I20260812 06:16:30.252283   564 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:30.254048   786 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:16:30.254467   564 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:30.254545   564 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/master-0-root
uuid: "1df9715fb3d844a3bcf17843530cf326"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-g350"
I20260812 06:16:30.254668   564 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-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:16:30.279914   564 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:30.280545   564 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:30.285482   564 rpc_server.cc:307] RPC server started. Bound to: 127.0.141.62:43319
I20260812 06:16:30.287470   848 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.141.62:43319 every 8 connection(s)
I20260812 06:16:30.288128   850 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:16:30.301045   850 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326: Bootstrap starting.
I20260812 06:16:30.302004   850 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:30.303424   850 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326: No bootstrap required, opened a new log
I20260812 06:16:30.303856   850 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER }
I20260812 06:16:30.303956   850 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:30.303979   850 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1df9715fb3d844a3bcf17843530cf326, State: Initialized, Role: FOLLOWER
I20260812 06:16:30.304152   850 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [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: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER }
I20260812 06:16:30.304260   850 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:30.304286   850 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:30.304317   850 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:30.305104   850 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER }
I20260812 06:16:30.305243   850 leader_election.cc:304] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [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: 1df9715fb3d844a3bcf17843530cf326; no voters: 
I20260812 06:16:30.305433   850 leader_election.cc:290] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:30.305653   854 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:30.305917   854 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 1 LEADER]: Becoming Leader. State: Replica: 1df9715fb3d844a3bcf17843530cf326, State: Running, Role: LEADER
I20260812 06:16:30.306149   850 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:30.306381   854 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [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: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER }
I20260812 06:16:30.307559   857 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1df9715fb3d844a3bcf17843530cf326. Latest consensus state: current_term: 1 leader_uuid: "1df9715fb3d844a3bcf17843530cf326" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER } }
I20260812 06:16:30.307668   857 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:30.307857   856 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1df9715fb3d844a3bcf17843530cf326" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1df9715fb3d844a3bcf17843530cf326" member_type: VOTER } }
I20260812 06:16:30.308004   856 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:30.308068   865 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:30.308867   865 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:30.309439   564 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:30.311897   865 catalog_manager.cc:1383] Generated new cluster ID: 6582cfc9128343ef815bef203a0306b2
I20260812 06:16:30.311990   865 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:30.345429   865 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:30.346122   865 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:30.353168   865 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326: Generated new TSK 0
I20260812 06:16:30.353430   865 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:30.375833   564 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:30.379027   877 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:16:30.379004   879 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:16:30.379269   564 server_base.cc:1061] running on GCE node
W20260812 06:16:30.379004   876 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:16:30.379666   564 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:30.379737   564 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:16:30.379766   564 hybrid_clock.cc:648] HybridClock initialized: now 1786515390379765 us; error 0 us; skew 500 ppm
I20260812 06:16:30.381098   564 webserver.cc:533] Webserver started at http://127.0.141.1:41359/ using document root <none> and password file <none>
I20260812 06:16:30.381341   564 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:30.381428   564 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:30.381523   564 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:30.382143   564 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/instance:
uuid: "3bac145ed70c4c5b903a44f2538a707e"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-g350"
I20260812 06:16:30.384397   564 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:30.386965   885 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:16:30.387277   564 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:30.387372   564 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root
uuid: "3bac145ed70c4c5b903a44f2538a707e"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-g350"
I20260812 06:16:30.387486   564 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-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:16:30.397998   564 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:30.398391   564 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:30.398679   564 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:30.399197   564 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:30.399240   564 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.399278   564 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:30.399295   564 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.404371   564 rpc_server.cc:307] RPC server started. Bound to: 127.0.141.1:36809
I20260812 06:16:30.405498   960 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.141.1:36809 every 8 connection(s)
I20260812 06:16:30.417558   961 heartbeater.cc:344] Connected to a master server at 127.0.141.62:43319
I20260812 06:16:30.417768   961 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:30.418061   961 heartbeater.cc:507] Master 127.0.141.62:43319 requested a full tablet report, sending...
I20260812 06:16:30.418960   806 ts_manager.cc:194] Registered new tserver with Master: 3bac145ed70c4c5b903a44f2538a707e (127.0.141.1:36809)
I20260812 06:16:30.419706   564 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014166171s
I20260812 06:16:30.419931   806 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60778
I20260812 06:16:30.428953   806 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60784:
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:16:30.439997   918 tablet_service.cc:1511] Processing CreateTablet for tablet 1d711cc70d8b4fcd9d0c9edffc2f74f9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9cb9bdc8bcb94862a5ad1ca35249b1a0]), partition=
I20260812 06:16:30.440332   918 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1d711cc70d8b4fcd9d0c9edffc2f74f9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:30.443135   974 tablet_bootstrap.cc:492] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Bootstrap starting.
I20260812 06:16:30.444087   974 tablet_bootstrap.cc:654] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:30.445364   974 tablet_bootstrap.cc:492] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: No bootstrap required, opened a new log
I20260812 06:16:30.445457   974 ts_tablet_manager.cc:1403] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:30.446046   974 raft_consensus.cc:359] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bac145ed70c4c5b903a44f2538a707e" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 36809 } }
I20260812 06:16:30.446151   974 raft_consensus.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:30.446199   974 raft_consensus.cc:740] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3bac145ed70c4c5b903a44f2538a707e, State: Initialized, Role: FOLLOWER
I20260812 06:16:30.446391   974 consensus_queue.cc:260] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [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: "3bac145ed70c4c5b903a44f2538a707e" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 36809 } }
I20260812 06:16:30.446516   974 raft_consensus.cc:399] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:30.446625   974 raft_consensus.cc:493] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:30.446692   974 raft_consensus.cc:3060] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:30.447894   974 raft_consensus.cc:515] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bac145ed70c4c5b903a44f2538a707e" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 36809 } }
I20260812 06:16:30.448076   974 leader_election.cc:304] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [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: 3bac145ed70c4c5b903a44f2538a707e; no voters: 
I20260812 06:16:30.448299   974 leader_election.cc:290] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:30.448550   977 raft_consensus.cc:2804] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:30.448769   977 raft_consensus.cc:697] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 1 LEADER]: Becoming Leader. State: Replica: 3bac145ed70c4c5b903a44f2538a707e, State: Running, Role: LEADER
I20260812 06:16:30.448968   961 heartbeater.cc:499] Master 127.0.141.62:43319 was elected leader, sending a full tablet report...
I20260812 06:16:30.448932   974 ts_tablet_manager.cc:1434] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:30.448933   977 consensus_queue.cc:237] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [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: "3bac145ed70c4c5b903a44f2538a707e" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 36809 } }
I20260812 06:16:30.450917   805 catalog_manager.cc:5719] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e reported cstate change: term changed from 0 to 1, leader changed from <none> to 3bac145ed70c4c5b903a44f2538a707e (127.0.141.1). New cstate: current_term: 1 leader_uuid: "3bac145ed70c4c5b903a44f2538a707e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bac145ed70c4c5b903a44f2538a707e" member_type: VOTER last_known_addr { host: "127.0.141.1" port: 36809 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:30.516601   564 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.016s	sys 0.008s
I20260812 06:16:30.656625   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=15.086190
I20260812 06:16:30.824988   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.167s	user 0.118s	sys 0.040s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1541,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40396,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:16:30.826201   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): free 8725963 bytes of WAL
I20260812 06:16:30.826541   893 log_reader.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9: removed 1 log segments from log reader
I20260812 06:16:30.826627   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000001 (ops 1-6)
I20260812 06:16:30.828526   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:30.828948   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:30.843678   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5547,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.844249   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): 12308959 bytes on disk
I20260812 06:16:30.844940   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.845498   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:30.995605   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.150s	user 0.108s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":766,"lbm_read_time_us":11260,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27383,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"thread_start_us":422,"threads_started":5,"update_count":2000}
I20260812 06:16:30.996563   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:31.050447   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.054s	user 0.016s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24231,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.051438   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:31.067366   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.016s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.067890   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:31.233836   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.166s	user 0.127s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1259,"lbm_read_time_us":11328,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28112,"lbm_writes_lt_1ms":443,"mutex_wait_us":351,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:16:31.234812   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:31.278990   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.044s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18742,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.279717   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:31.294603   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.295382   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:31.438598   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.143s	user 0.084s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1357,"lbm_read_time_us":9853,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26538,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.439489   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:31.484668   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.045s	user 0.038s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20041,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.485301   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:31.496665   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.497414   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:31.637497   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.140s	user 0.108s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":9645,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26653,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:16:31.638288   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:31.678337   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17206,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.678862   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:31.790227   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.111s	user 0.102s	sys 0.008s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1069,"lbm_read_time_us":7637,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21060,"lbm_writes_lt_1ms":343,"mutex_wait_us":166,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":1500}
I20260812 06:16:31.790889   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:31.839488   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.048s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.840163   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:31.854842   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.855404   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:32.018191   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.162s	user 0.134s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":828,"lbm_read_time_us":9430,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31211,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":158976,"update_count":2000}
I20260812 06:16:32.018747   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:32.072252   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.053s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18930,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.072863   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:32.088356   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.089112   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:32.233058   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.144s	user 0.114s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1008,"lbm_read_time_us":9951,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27594,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43392,"update_count":2000}
I20260812 06:16:32.233753   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=10.126437
I20260812 06:16:32.290459   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.057s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20511,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.291249   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:32.303308   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.303918   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:32.342902   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.039s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":127,"dirs.run_cpu_time_us":475,"dirs.run_wall_time_us":2232,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:32.343623   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): free 128867436 bytes of WAL
I20260812 06:16:32.343887   893 log_reader.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9: removed 13 log segments from log reader
I20260812 06:16:32.343954   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000002 (ops 7-11)
I20260812 06:16:32.344012   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000003 (ops 12-16)
I20260812 06:16:32.344074   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000004 (ops 17-20)
I20260812 06:16:32.344116   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000005 (ops 21-25)
I20260812 06:16:32.344156   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000006 (ops 26-30)
I20260812 06:16:32.344201   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000007 (ops 31-34)
I20260812 06:16:32.344237   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000008 (ops 35-39)
I20260812 06:16:32.344269   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000009 (ops 40-44)
I20260812 06:16:32.344307   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000010 (ops 45-49)
I20260812 06:16:32.344344   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000011 (ops 50-54)
I20260812 06:16:32.344379   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000012 (ops 55-58)
I20260812 06:16:32.344415   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000013 (ops 59-63)
I20260812 06:16:32.344451   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000014 (ops 64-68)
I20260812 06:16:32.379339   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:16:32.380429   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=4.173312
I20260812 06:16:32.396008   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5456464,"delete_count":0,"lbm_write_time_us":5956,"lbm_writes_lt_1ms":136,"reinsert_count":0,"update_count":665}
I20260812 06:16:32.396607   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): free 11564875 bytes of WAL
I20260812 06:16:32.396859   893 log_reader.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9: removed 1 log segments from log reader
I20260812 06:16:32.396903   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000015 (ops 69-72)
I20260812 06:16:32.399446   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:32.400130   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.196750
I20260812 06:16:32.411576   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:16:32.412424   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:32.600587   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.188s	user 0.156s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836344,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":666,"lbm_read_time_us":13432,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35933,"lbm_writes_lt_1ms":643,"mutex_wait_us":86,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19584,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:16:32.601547   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): 483 bytes on disk
I20260812 06:16:32.602298   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":142,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.603004   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:32.651664   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.048s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20880,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.653002   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:32.672467   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.019s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.673048   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:32.863783   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.191s	user 0.161s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1195,"lbm_read_time_us":9517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37014,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2500}
I20260812 06:16:32.864745   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:32.955545   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.090s	user 0.061s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":34566,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.956689   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:32.970141   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.970840   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:33.182510   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.211s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1405,"lbm_read_time_us":13611,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33888,"lbm_writes_lt_1ms":543,"mutex_wait_us":485,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:16:33.183395   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:33.250730   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.067s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29468,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.251524   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:33.264246   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.264873   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:33.467522   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.202s	user 0.156s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":13874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33031,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:33.470144   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:33.542786   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.072s	user 0.029s	sys 0.040s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27945,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.543469   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:33.557505   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.558145   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:33.778903   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.221s	user 0.159s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":14720,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36400,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:16:33.779858   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=11.118625
I20260812 06:16:33.823801   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.044s	user 0.013s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19742,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:33.824398   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:33.864596   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.040s	user 0.009s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5842,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.865272   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:33.879269   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5460,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.879944   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:34.113765   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.234s	user 0.147s	sys 0.070s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":978,"lbm_read_time_us":14154,"lbm_reads_lt_1ms":573,"lbm_write_time_us":36948,"lbm_writes_lt_1ms":543,"mutex_wait_us":356,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:16:34.114955   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:34.177928   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.063s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27128,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.179353   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:34.197769   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.018s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.199144   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:34.248353   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.049s	user 0.045s	sys 0.000s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":336,"dirs.run_wall_time_us":2061,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2140,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:16:34.249476   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): free 129320483 bytes of WAL
I20260812 06:16:34.250154   893 log_reader.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9: removed 13 log segments from log reader
I20260812 06:16:34.250339   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000016 (ops 73-77)
I20260812 06:16:34.250388   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000017 (ops 78-82)
I20260812 06:16:34.250415   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000018 (ops 83-86)
I20260812 06:16:34.250500   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000019 (ops 87-91)
I20260812 06:16:34.250553   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000020 (ops 92-96)
I20260812 06:16:34.250587   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000021 (ops 97-101)
I20260812 06:16:34.250650   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000022 (ops 102-106)
I20260812 06:16:34.250692   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000023 (ops 107-111)
I20260812 06:16:34.250717   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000024 (ops 112-116)
I20260812 06:16:34.250787   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000025 (ops 117-121)
I20260812 06:16:34.250835   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000026 (ops 122-126)
I20260812 06:16:34.250900   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000027 (ops 127-130)
I20260812 06:16:34.250947   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000028 (ops 131-135)
I20260812 06:16:34.286554   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.036s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:16:34.287103   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): 508 bytes on disk
I20260812 06:16:34.287680   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: UndoDeltaBlockGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.289302   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=5.165500
I20260812 06:16:34.310933   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.021s	user 0.019s	sys 0.001s Metrics: {"bytes_written":6523087,"delete_count":0,"lbm_write_time_us":9028,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:16:34.311707   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:34.320641   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.009s	user 0.003s	sys 0.003s Metrics: {"bytes_written":1682177,"delete_count":0,"lbm_write_time_us":2463,"lbm_writes_lt_1ms":44,"reinsert_count":0,"update_count":205}
I20260812 06:16:34.321283   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:34.596273   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.275s	user 0.196s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6006,"lbm_read_time_us":17261,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45432,"lbm_writes_lt_1ms":743,"mutex_wait_us":2750,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15232,"thread_start_us":138,"threads_started":1,"update_count":3500}
I20260812 06:16:34.597221   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=18.063937
I20260812 06:16:34.673367   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.076s	user 0.035s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30108,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:34.674125   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:34.690032   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.690840   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:34.949326   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.258s	user 0.189s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":714,"lbm_read_time_us":18297,"lbm_reads_lt_1ms":672,"lbm_write_time_us":41768,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":3000}
I20260812 06:16:34.950361   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=15.087375
I20260812 06:16:35.023332   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.073s	user 0.032s	sys 0.039s Metrics: {"bytes_written":16738095,"delete_count":0,"lbm_write_time_us":34235,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":407,"reinsert_count":0,"update_count":2040}
I20260812 06:16:35.024255   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:35.042032   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5675,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:35.042717   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:35.246924   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.204s	user 0.126s	sys 0.077s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733717,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":14994,"lbm_reads_lt_1ms":568,"lbm_write_time_us":36315,"lbm_writes_lt_1ms":543,"mutex_wait_us":6,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:16:35.247659   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:35.313217   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.065s	user 0.025s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.313946   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:35.332938   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.333499   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:35.524933   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.191s	user 0.135s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":489,"lbm_read_time_us":14285,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32668,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:35.525683   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:35.599047   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.073s	user 0.043s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28102,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.599936   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:35.611760   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.612354   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:35.838115   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.226s	user 0.144s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":435,"lbm_read_time_us":14730,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40384,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:16:35.838837   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:35.910861   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.072s	user 0.034s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30719,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"mutex_wait_us":24,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.911540   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:35.937729   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.026s	user 0.010s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.938519   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:36.181474   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.243s	user 0.152s	sys 0.090s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":657,"lbm_read_time_us":17023,"lbm_reads_lt_1ms":572,"lbm_write_time_us":43650,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":902528,"update_count":2500}
I20260812 06:16:36.182561   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=14.095187
I20260812 06:16:36.244848   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.062s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28065,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.245653   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:36.267848   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.022s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.268455   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:36.288733   564 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.772s	user 2.162s	sys 0.182s
I20260812 06:16:36.322219   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushMRSOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.054s	user 0.026s	sys 0.008s Metrics: {"bytes_written":1357578,"cfile_init":1,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":376,"dirs.run_wall_time_us":1925,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2837,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33,"spinlock_wait_cycles":1792}
I20260812 06:16:36.323020   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): free 132571656 bytes of WAL
I20260812 06:16:36.323282   893 log_reader.cc:385] T 1d711cc70d8b4fcd9d0c9edffc2f74f9: removed 13 log segments from log reader
I20260812 06:16:36.323331   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000029 (ops 136-140)
I20260812 06:16:36.323364   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000030 (ops 141-145)
I20260812 06:16:36.323424   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000031 (ops 146-150)
I20260812 06:16:36.323462   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000032 (ops 151-154)
I20260812 06:16:36.323506   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000033 (ops 155-159)
I20260812 06:16:36.323542   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000034 (ops 160-164)
I20260812 06:16:36.323585   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000035 (ops 165-169)
I20260812 06:16:36.323621   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000036 (ops 170-174)
I20260812 06:16:36.323660   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000037 (ops 175-179)
I20260812 06:16:36.323688   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000038 (ops 180-184)
I20260812 06:16:36.323725   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000039 (ops 185-189)
I20260812 06:16:36.323765   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000040 (ops 190-194)
I20260812 06:16:36.323804   893 log.cc:1079] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: Deleting log segment in path: /tmp/dist-test-taskhqHj9u/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515384034829-564-0/minicluster-data/ts-0-root/wals/1d711cc70d8b4fcd9d0c9edffc2f74f9/wal-000000041 (ops 195-198)
I20260812 06:16:36.350247   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: LogGCOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:36.350728   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=2.188937
I20260812 06:16:36.363533   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: FlushDeltaMemStoresOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.364097   962 maintenance_manager.cc:419] P 3bac145ed70c4c5b903a44f2538a707e: Scheduling MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9): perf score=1.000000
I20260812 06:16:36.369946   564 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.003s	sys 0.000s
I20260812 06:16:36.370537   564 tablet_server.cc:179] TabletServer@127.0.141.1:0 shutting down...
I20260812 06:16:36.517805   893 maintenance_manager.cc:643] P 3bac145ed70c4c5b903a44f2538a707e: MajorDeltaCompactionOp(1d711cc70d8b4fcd9d0c9edffc2f74f9) complete. Timing: real 0.154s	user 0.104s	sys 0.048s Metrics: {"cfile_cache_hit":532,"cfile_cache_hit_bytes":24733725,"cfile_cache_miss":101,"cfile_cache_miss_bytes":4102530,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1285,"lbm_read_time_us":2545,"lbm_reads_lt_1ms":113,"lbm_write_time_us":33389,"lbm_writes_lt_1ms":643,"mutex_wait_us":380,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":73088,"thread_start_us":159,"threads_started":1,"update_count":3000}
I20260812 06:16:36.519063   564 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:36.519440   564 tablet_replica.cc:333] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e: stopping tablet replica
I20260812 06:16:36.519773   564 raft_consensus.cc:2243] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:36.520095   564 raft_consensus.cc:2272] T 1d711cc70d8b4fcd9d0c9edffc2f74f9 P 3bac145ed70c4c5b903a44f2538a707e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:36.537930   564 tablet_server.cc:196] TabletServer@127.0.141.1:0 shutdown complete.
I20260812 06:16:36.570749   564 master.cc:562] Master@127.0.141.62:43319 shutting down...
I20260812 06:16:36.575824   564 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:36.576093   564 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:36.576182   564 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1df9715fb3d844a3bcf17843530cf326: stopping tablet replica
I20260812 06:16:36.589877   564 master.cc:584] Master@127.0.141.62:43319 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6437 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12637 ms total)

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