[==========] 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:23.009460 22747 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.54.254:33855
I20260812 06:16:23.010543 22747 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:23.011214 22747 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.018591 22752 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:23.018821 22755 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:23.019076 22753 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:23.019194 22747 server_base.cc:1061] running on GCE node
I20260812 06:16:23.019629 22747 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.019783 22747 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:23.019815 22747 hybrid_clock.cc:648] HybridClock initialized: now 1786515383019813 us; error 0 us; skew 500 ppm
I20260812 06:16:23.021950 22747 webserver.cc:533] Webserver started at http://127.22.54.254:38149/ using document root <none> and password file <none>
I20260812 06:16:23.022567 22747 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.022629 22747 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.022934 22747 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.024632 22747 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/master-0-root/instance:
uuid: "f26a2dfb03774491a7054c549fbe5c21"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-9gcw"
I20260812 06:16:23.028419 22747 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.006s	sys 0.000s
I20260812 06:16:23.031045 22760 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:23.032226 22747 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:16:23.032392 22747 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/master-0-root
uuid: "f26a2dfb03774491a7054c549fbe5c21"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-9gcw"
I20260812 06:16:23.032514 22747 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-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:23.044955 22747 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.045926 22747 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:23.046145 22747 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.054548 22747 rpc_server.cc:307] RPC server started. Bound to: 127.22.54.254:33855
I20260812 06:16:23.054595 22820 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.54.254:33855 every 8 connection(s)
I20260812 06:16:23.057005 22821 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:23.062969 22821 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: Bootstrap starting.
I20260812 06:16:23.065501 22821 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.066548 22821 log.cc:826] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:23.068548 22821 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: No bootstrap required, opened a new log
I20260812 06:16:23.071604 22821 raft_consensus.cc:359] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER }
I20260812 06:16:23.071794 22821 raft_consensus.cc:385] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.071887 22821 raft_consensus.cc:740] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f26a2dfb03774491a7054c549fbe5c21, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.072650 22821 consensus_queue.cc:260] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [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: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER }
I20260812 06:16:23.072813 22821 raft_consensus.cc:399] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.072901 22821 raft_consensus.cc:493] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.073069 22821 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.073952 22821 raft_consensus.cc:515] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER }
I20260812 06:16:23.074422 22821 leader_election.cc:304] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [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: f26a2dfb03774491a7054c549fbe5c21; no voters: 
I20260812 06:16:23.074770 22821 leader_election.cc:290] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.075011 22826 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.075322 22826 raft_consensus.cc:697] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 1 LEADER]: Becoming Leader. State: Replica: f26a2dfb03774491a7054c549fbe5c21, State: Running, Role: LEADER
I20260812 06:16:23.075796 22826 consensus_queue.cc:237] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [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: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER }
I20260812 06:16:23.075830 22821 sys_catalog.cc:565] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:23.078105 22828 sys_catalog.cc:455] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f26a2dfb03774491a7054c549fbe5c21. Latest consensus state: current_term: 1 leader_uuid: "f26a2dfb03774491a7054c549fbe5c21" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER } }
I20260812 06:16:23.078137 22827 sys_catalog.cc:455] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f26a2dfb03774491a7054c549fbe5c21" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26a2dfb03774491a7054c549fbe5c21" member_type: VOTER } }
I20260812 06:16:23.078233 22828 sys_catalog.cc:458] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.078239 22827 sys_catalog.cc:458] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.078367 22747 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:23.080376 22842 catalog_manager.cc:1594] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:23.080471 22842 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:23.080538 22843 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:23.081372 22843 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:23.086885 22843 catalog_manager.cc:1383] Generated new cluster ID: 96fcc6e244314fb8a8a834e07ee2a2f1
I20260812 06:16:23.086982 22843 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:23.097321 22843 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:23.098265 22843 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:23.117632 22843 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: Generated new TSK 0
I20260812 06:16:23.118364 22843 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.143543 22747 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.146955 22849 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:23.146981 22847 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:23.147244 22851 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:23.147336 22747 server_base.cc:1061] running on GCE node
I20260812 06:16:23.147609 22747 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.147687 22747 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:23.147719 22747 hybrid_clock.cc:648] HybridClock initialized: now 1786515383147718 us; error 0 us; skew 500 ppm
I20260812 06:16:23.148825 22747 webserver.cc:533] Webserver started at http://127.22.54.193:44497/ using document root <none> and password file <none>
I20260812 06:16:23.149050 22747 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.149135 22747 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.149264 22747 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.149698 22747 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/instance:
uuid: "9882c9bdb40f44118a44534756670b55"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-9gcw"
I20260812 06:16:23.151405 22747 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:23.152508 22859 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:23.152781 22747 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.152859 22747 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root
uuid: "9882c9bdb40f44118a44534756670b55"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-9gcw"
I20260812 06:16:23.152956 22747 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-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:23.159909 22747 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.160403 22747 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.161000 22747 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.162019 22747 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.162077 22747 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.162124 22747 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.162142 22747 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.174718 22747 rpc_server.cc:307] RPC server started. Bound to: 127.22.54.193:45105
I20260812 06:16:23.174861 22932 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.54.193:45105 every 8 connection(s)
I20260812 06:16:23.192085 22933 heartbeater.cc:344] Connected to a master server at 127.22.54.254:33855
I20260812 06:16:23.192384 22933 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.192937 22933 heartbeater.cc:507] Master 127.22.54.254:33855 requested a full tablet report, sending...
I20260812 06:16:23.194672 22782 ts_manager.cc:194] Registered new tserver with Master: 9882c9bdb40f44118a44534756670b55 (127.22.54.193:45105)
I20260812 06:16:23.195083 22747 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019356667s
I20260812 06:16:23.196579 22782 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50990
I20260812 06:16:23.207700 22782 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50992:
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:23.226410 22893 tablet_service.cc:1511] Processing CreateTablet for tablet d2c07163fcd549f0be9a8fc66023d911 (DEFAULT_TABLE table=heavy-update-compaction-test [id=415d8a342b914df4bdaefa5d142fe20e]), partition=
I20260812 06:16:23.227067 22893 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d2c07163fcd549f0be9a8fc66023d911. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.232028 22947 tablet_bootstrap.cc:492] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Bootstrap starting.
I20260812 06:16:23.234071 22947 tablet_bootstrap.cc:654] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.236346 22947 tablet_bootstrap.cc:492] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: No bootstrap required, opened a new log
I20260812 06:16:23.236584 22947 ts_tablet_manager.cc:1403] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Time spent bootstrapping tablet: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:16:23.237705 22947 raft_consensus.cc:359] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9882c9bdb40f44118a44534756670b55" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45105 } }
I20260812 06:16:23.237851 22947 raft_consensus.cc:385] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.237913 22947 raft_consensus.cc:740] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9882c9bdb40f44118a44534756670b55, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.238098 22947 consensus_queue.cc:260] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [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: "9882c9bdb40f44118a44534756670b55" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45105 } }
I20260812 06:16:23.238224 22947 raft_consensus.cc:399] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.238296 22947 raft_consensus.cc:493] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.238356 22947 raft_consensus.cc:3060] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.240033 22947 raft_consensus.cc:515] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9882c9bdb40f44118a44534756670b55" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45105 } }
I20260812 06:16:23.240154 22947 leader_election.cc:304] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [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: 9882c9bdb40f44118a44534756670b55; no voters: 
I20260812 06:16:23.240485 22947 leader_election.cc:290] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.240752 22951 raft_consensus.cc:2804] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.241288 22951 raft_consensus.cc:697] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 1 LEADER]: Becoming Leader. State: Replica: 9882c9bdb40f44118a44534756670b55, State: Running, Role: LEADER
I20260812 06:16:23.241344 22947 ts_tablet_manager.cc:1434] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Time spent starting tablet: real 0.005s	user 0.005s	sys 0.000s
I20260812 06:16:23.241446 22951 consensus_queue.cc:237] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [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: "9882c9bdb40f44118a44534756670b55" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45105 } }
I20260812 06:16:23.241783 22933 heartbeater.cc:499] Master 127.22.54.254:33855 was elected leader, sending a full tablet report...
I20260812 06:16:23.245049 22782 catalog_manager.cc:5719] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9882c9bdb40f44118a44534756670b55 (127.22.54.193). New cstate: current_term: 1 leader_uuid: "9882c9bdb40f44118a44534756670b55" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9882c9bdb40f44118a44534756670b55" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45105 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.326753 22747 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.073s	user 0.029s	sys 0.008s
I20260812 06:16:23.426265 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911): perf score=10.125253
I20260812 06:16:23.573395 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.147s	user 0.107s	sys 0.037s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":245,"delete_count":0,"dirs.queue_time_us":377,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1119,"drs_written":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36871,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":153,"threads_started":1,"update_count":1000}
I20260812 06:16:23.574569 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 8725963 bytes of WAL
I20260812 06:16:23.574882 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 1 log segments from log reader
I20260812 06:16:23.574960 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000001 (ops 1-6)
I20260812 06:16:23.576958 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:23.577315 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911): 8616794 bytes on disk
I20260812 06:16:23.578020 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:16:23.578428 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:23.590806 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:23.591391 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:23.720963 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.129s	user 0.093s	sys 0.036s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16118646,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1335,"lbm_read_time_us":7113,"lbm_reads_lt_1ms":350,"lbm_write_time_us":29236,"lbm_writes_lt_1ms":333,"mutex_wait_us":119,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":504,"threads_started":5,"update_count":1450}
I20260812 06:16:23.721619 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=6.157687
I20260812 06:16:23.753371 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.032s	user 0.020s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11858,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:23.753862 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:23.764920 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.765435 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:23.904273 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.139s	user 0.094s	sys 0.031s 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":649,"lbm_read_time_us":8156,"lbm_reads_lt_1ms":372,"lbm_write_time_us":24766,"lbm_writes_lt_1ms":343,"mutex_wait_us":64,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":1500}
I20260812 06:16:23.904958 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=10.126437
I20260812 06:16:23.950500 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20271,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:23.951064 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:23.963582 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.964109 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:24.112478 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.148s	user 0.106s	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":286,"lbm_read_time_us":9199,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34060,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:16:24.113011 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=10.126437
I20260812 06:16:24.161418 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.048s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19733,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.162154 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:24.177465 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5436,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.178153 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:24.337921 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.160s	user 0.118s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":9019,"lbm_reads_lt_1ms":464,"lbm_write_time_us":39480,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29568,"update_count":2000}
I20260812 06:16:24.338449 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:24.399246 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.061s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.399840 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:24.412340 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.412968 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:24.609062 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.196s	user 0.123s	sys 0.068s 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":813,"dirs.run_cpu_time_us":572,"dirs.run_wall_time_us":3787,"lbm_read_time_us":11275,"lbm_reads_lt_1ms":572,"lbm_write_time_us":43503,"lbm_writes_lt_1ms":543,"mutex_wait_us":95,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:24.609892 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:24.672094 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.062s	user 0.017s	sys 0.042s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.672740 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:24.692489 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.692976 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:24.868110 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.175s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1039,"lbm_read_time_us":10933,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34266,"lbm_writes_lt_1ms":543,"mutex_wait_us":127,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":92,"threads_started":1,"update_count":2500}
I20260812 06:16:24.868789 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:24.938673 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.070s	user 0.041s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29049,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.939306 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:24.953608 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.954260 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:24.986836 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1638,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1756,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:24.987804 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 124257180 bytes of WAL
I20260812 06:16:24.988070 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 12 log segments from log reader
I20260812 06:16:24.988121 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000002 (ops 7-11)
I20260812 06:16:24.988186 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000003 (ops 12-16)
I20260812 06:16:24.988242 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000004 (ops 17-20)
I20260812 06:16:24.988291 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000005 (ops 21-25)
I20260812 06:16:24.988339 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000006 (ops 26-30)
I20260812 06:16:24.988385 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000007 (ops 31-35)
I20260812 06:16:24.988431 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000008 (ops 36-40)
I20260812 06:16:24.988495 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000009 (ops 41-45)
I20260812 06:16:24.988538 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000010 (ops 46-50)
I20260812 06:16:24.988581 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000011 (ops 51-55)
I20260812 06:16:24.988627 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000012 (ops 56-60)
I20260812 06:16:24.988684 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000013 (ops 61-65)
I20260812 06:16:25.018741 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:25.019692 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911): 447 bytes on disk
I20260812 06:16:25.020479 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:16:25.021257 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=5.165500
I20260812 06:16:25.037933 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.016s	user 0.014s	sys 0.002s Metrics: {"bytes_written":6728210,"delete_count":0,"lbm_write_time_us":6534,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:16:25.038488 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:25.046893 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2428,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:16:25.047318 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:25.282415 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.235s	user 0.171s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":699,"lbm_read_time_us":13217,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39554,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:16:25.283429 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=18.063937
I20260812 06:16:25.355592 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.072s	user 0.033s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27963,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:25.356192 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:25.368638 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.369510 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:25.595221 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.225s	user 0.153s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1127,"lbm_read_time_us":16014,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40034,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":90240,"update_count":3000}
I20260812 06:16:25.596015 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=16.079562
I20260812 06:16:25.671068 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.075s	user 0.040s	sys 0.027s Metrics: {"bytes_written":17681655,"delete_count":0,"lbm_write_time_us":31499,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":431,"reinsert_count":0,"update_count":2155}
I20260812 06:16:25.671564 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=5.165500
I20260812 06:16:25.691499 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":6933336,"delete_count":0,"lbm_write_time_us":7949,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:16:25.692194 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:25.921860 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.229s	user 0.151s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836148,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":15375,"lbm_reads_lt_1ms":664,"lbm_write_time_us":45738,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":3000}
I20260812 06:16:25.922470 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=18.063937
I20260812 06:16:25.997428 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.075s	user 0.052s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28895,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:25.997936 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:26.010797 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.011391 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:26.243091 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.232s	user 0.155s	sys 0.067s 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":253,"lbm_read_time_us":13890,"lbm_reads_lt_1ms":672,"lbm_write_time_us":43140,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":3000}
I20260812 06:16:26.243942 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=18.063937
I20260812 06:16:26.314160 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.070s	user 0.054s	sys 0.007s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28291,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.314785 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:26.329172 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.329823 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:26.559319 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.229s	user 0.164s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":912,"lbm_read_time_us":15854,"lbm_reads_lt_1ms":672,"lbm_write_time_us":50104,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":3000}
I20260812 06:16:26.560086 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=18.063937
I20260812 06:16:26.628638 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.068s	user 0.041s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32426,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.629437 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:26.644014 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.644634 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:26.679183 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.034s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1804,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2046,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:26.680171 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 124710313 bytes of WAL
I20260812 06:16:26.680488 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 12 log segments from log reader
I20260812 06:16:26.680612 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000014 (ops 66-70)
I20260812 06:16:26.680683 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000015 (ops 71-75)
I20260812 06:16:26.680722 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000016 (ops 76-80)
I20260812 06:16:26.680748 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000017 (ops 81-85)
I20260812 06:16:26.680778 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000018 (ops 86-90)
I20260812 06:16:26.680809 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000019 (ops 91-95)
I20260812 06:16:26.680833 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000020 (ops 96-100)
I20260812 06:16:26.680866 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000021 (ops 101-105)
I20260812 06:16:26.680898 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000022 (ops 106-110)
I20260812 06:16:26.680936 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000023 (ops 111-115)
I20260812 06:16:26.680976 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000024 (ops 116-120)
I20260812 06:16:26.681015 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000025 (ops 121-125)
I20260812 06:16:26.711829 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:26.712441 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=5.165500
I20260812 06:16:26.733291 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":7138450,"delete_count":0,"lbm_write_time_us":8489,"lbm_writes_lt_1ms":177,"reinsert_count":0,"update_count":870}
I20260812 06:16:26.733809 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 12017991 bytes of WAL
I20260812 06:16:26.734068 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 1 log segments from log reader
I20260812 06:16:26.734148 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000026 (ops 126-130)
I20260812 06:16:26.737205 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.003s	user 0.003s	sys 0.000s Metrics: {}
I20260812 06:16:26.737567 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911): 493 bytes on disk
I20260812 06:16:26.738219 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:16:26.738807 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:26.981979 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.243s	user 0.159s	sys 0.080s Metrics: {"cfile_cache_miss":807,"cfile_cache_miss_bytes":35974453,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":306,"lbm_read_time_us":19085,"lbm_reads_lt_1ms":843,"lbm_write_time_us":42823,"lbm_writes_lt_1ms":817,"mutex_wait_us":76,"peak_mem_usage":97247938,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":81,"threads_started":1,"update_count":3870}
I20260812 06:16:26.982658 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=19.056125
I20260812 06:16:27.048260 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.065s	user 0.026s	sys 0.036s Metrics: {"bytes_written":21578948,"delete_count":0,"lbm_write_time_us":28864,"lbm_writes_lt_1ms":529,"reinsert_count":0,"update_count":2630}
I20260812 06:16:27.048852 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:27.069648 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.021s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.070333 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:27.264487 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.194s	user 0.157s	sys 0.036s Metrics: {"cfile_cache_miss":658,"cfile_cache_miss_bytes":29902770,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":13970,"lbm_reads_lt_1ms":694,"lbm_write_time_us":42331,"lbm_writes_lt_1ms":669,"peak_mem_usage":78690150,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":3130}
I20260812 06:16:27.265280 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:27.315840 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.049s	user 0.041s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21253,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.316496 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:27.333890 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.334539 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:27.510629 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.176s	user 0.129s	sys 0.036s 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":1283,"lbm_read_time_us":10996,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32079,"lbm_writes_lt_1ms":543,"mutex_wait_us":394,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:16:27.511206 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:27.560659 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.049s	user 0.021s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23606,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.561241 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:27.719044 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.158s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":882,"lbm_read_time_us":8926,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29968,"lbm_writes_lt_1ms":443,"mutex_wait_us":347,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:16:27.719635 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=11.118625
I20260812 06:16:27.764040 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.044s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":21402,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:27.764688 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:27.785650 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.021s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.786194 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:27.797127 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.797772 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:28.004022 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.206s	user 0.119s	sys 0.083s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":583,"lbm_read_time_us":13012,"lbm_reads_lt_1ms":573,"lbm_write_time_us":42055,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:16:28.004773 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=14.095187
I20260812 06:16:28.068264 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.063s	user 0.031s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":32616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.068816 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:28.081540 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.082132 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:28.271297 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.189s	user 0.124s	sys 0.059s 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":661,"lbm_read_time_us":12445,"lbm_reads_lt_1ms":572,"lbm_write_time_us":39945,"lbm_writes_lt_1ms":543,"mutex_wait_us":264,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:16:28.272078 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=11.118625
I20260812 06:16:28.341406 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.069s	user 0.029s	sys 0.027s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":27951,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:28.341964 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=6.157687
I20260812 06:16:28.375155 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.033s	user 0.022s	sys 0.005s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":12720,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:28.375707 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:28.429018 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushMRSOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.053s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1409,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2587,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:16:28.429863 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 121459760 bytes of WAL
I20260812 06:16:28.430152 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 12 log segments from log reader
I20260812 06:16:28.430212 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000027 (ops 131-135)
I20260812 06:16:28.430251 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000028 (ops 136-140)
I20260812 06:16:28.430284 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000029 (ops 141-145)
I20260812 06:16:28.430316 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000030 (ops 146-150)
I20260812 06:16:28.430342 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000031 (ops 151-155)
I20260812 06:16:28.430370 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000032 (ops 156-160)
I20260812 06:16:28.430401 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000033 (ops 161-165)
I20260812 06:16:28.430436 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000034 (ops 166-170)
I20260812 06:16:28.430467 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000035 (ops 171-175)
I20260812 06:16:28.430493 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000036 (ops 176-180)
I20260812 06:16:28.430522 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000037 (ops 181-185)
I20260812 06:16:28.430549 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000038 (ops 186-190)
I20260812 06:16:28.461417 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:16:28.461952 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=6.157687
I20260812 06:16:28.497777 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":14891,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:28.498359 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling LogGCOp(d2c07163fcd549f0be9a8fc66023d911): free 12017897 bytes of WAL
I20260812 06:16:28.498611 22866 log_reader.cc:385] T d2c07163fcd549f0be9a8fc66023d911: removed 1 log segments from log reader
I20260812 06:16:28.498667 22866 log.cc:1079] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/d2c07163fcd549f0be9a8fc66023d911/wal-000000039 (ops 191-195)
I20260812 06:16:28.501300 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: LogGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:28.501708 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911): 507 bytes on disk
I20260812 06:16:28.502206 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: UndoDeltaBlockGCOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.502846 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911): perf score=2.188937
I20260812 06:16:28.518821 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: FlushDeltaMemStoresOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.519384 22934 maintenance_manager.cc:419] P 9882c9bdb40f44118a44534756670b55: Scheduling MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911): perf score=1.000000
I20260812 06:16:28.588366 22747 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.261s	user 1.853s	sys 0.188s
I20260812 06:16:28.710091 22747 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.121s	user 0.003s	sys 0.000s
I20260812 06:16:28.710763 22747 tablet_server.cc:179] TabletServer@127.22.54.193:0 shutting down...
I20260812 06:16:28.760211 22866 maintenance_manager.cc:643] P 9882c9bdb40f44118a44534756670b55: MajorDeltaCompactionOp(d2c07163fcd549f0be9a8fc66023d911) complete. Timing: real 0.241s	user 0.148s	sys 0.091s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37041202,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1051,"lbm_read_time_us":17841,"lbm_reads_lt_1ms":862,"lbm_write_time_us":38459,"lbm_writes_lt_1ms":843,"mutex_wait_us":445,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":33408,"thread_start_us":94,"threads_started":1,"update_count":4000}
I20260812 06:16:28.761814 22747 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:28.762326 22747 tablet_replica.cc:333] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55: stopping tablet replica
I20260812 06:16:28.762617 22747 raft_consensus.cc:2243] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.762915 22747 raft_consensus.cc:2272] T d2c07163fcd549f0be9a8fc66023d911 P 9882c9bdb40f44118a44534756670b55 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.769557 22747 tablet_server.cc:196] TabletServer@127.22.54.193:0 shutdown complete.
I20260812 06:16:28.834250 22747 master.cc:562] Master@127.22.54.254:33855 shutting down...
I20260812 06:16:28.838212 22747 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.838420 22747 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.838501 22747 tablet_replica.cc:333] T 00000000000000000000000000000000 P f26a2dfb03774491a7054c549fbe5c21: stopping tablet replica
I20260812 06:16:28.851190 22747 master.cc:584] Master@127.22.54.254:33855 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5938 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:28.947569 22747 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.54.254:33233
I20260812 06:16:28.948112 22747 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.950937 22975 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:28.950945 22978 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:28.951200 22747 server_base.cc:1061] running on GCE node
W20260812 06:16:28.951013 22974 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:28.951511 22747 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.951558 22747 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:28.951575 22747 hybrid_clock.cc:648] HybridClock initialized: now 1786515388951575 us; error 0 us; skew 500 ppm
I20260812 06:16:28.952517 22747 webserver.cc:533] Webserver started at http://127.22.54.254:33601/ using document root <none> and password file <none>
I20260812 06:16:28.952752 22747 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.952807 22747 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.952865 22747 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.953323 22747 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/master-0-root/instance:
uuid: "ecad3669e735401198a20bb9e9915a92"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-9gcw"
I20260812 06:16:28.954896 22747 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:28.955981 22984 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:28.956307 22747 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.956373 22747 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/master-0-root
uuid: "ecad3669e735401198a20bb9e9915a92"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-9gcw"
I20260812 06:16:28.956429 22747 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-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:28.995496 22747 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.995894 22747 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:29.000181 22747 rpc_server.cc:307] RPC server started. Bound to: 127.22.54.254:33233
I20260812 06:16:29.003079 23039 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.54.254:33233 every 8 connection(s)
I20260812 06:16:29.003815 23040 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:29.013602 23040 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92: Bootstrap starting.
I20260812 06:16:29.014535 23040 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:29.015823 23040 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92: No bootstrap required, opened a new log
I20260812 06:16:29.016199 23040 raft_consensus.cc:359] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER }
I20260812 06:16:29.016291 23040 raft_consensus.cc:385] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:29.016314 23040 raft_consensus.cc:740] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ecad3669e735401198a20bb9e9915a92, State: Initialized, Role: FOLLOWER
I20260812 06:16:29.016422 23040 consensus_queue.cc:260] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [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: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER }
I20260812 06:16:29.016530 23040 raft_consensus.cc:399] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:29.016580 23040 raft_consensus.cc:493] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:29.016646 23040 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:29.017411 23040 raft_consensus.cc:515] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER }
I20260812 06:16:29.017578 23040 leader_election.cc:304] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [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: ecad3669e735401198a20bb9e9915a92; no voters: 
I20260812 06:16:29.017824 23040 leader_election.cc:290] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:29.017957 23043 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:29.018193 23043 raft_consensus.cc:697] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 1 LEADER]: Becoming Leader. State: Replica: ecad3669e735401198a20bb9e9915a92, State: Running, Role: LEADER
I20260812 06:16:29.018303 23040 sys_catalog.cc:565] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:29.018370 23043 consensus_queue.cc:237] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [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: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER }
I20260812 06:16:29.018833 23044 sys_catalog.cc:455] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ecad3669e735401198a20bb9e9915a92" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER } }
I20260812 06:16:29.018863 23046 sys_catalog.cc:455] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ecad3669e735401198a20bb9e9915a92. Latest consensus state: current_term: 1 leader_uuid: "ecad3669e735401198a20bb9e9915a92" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecad3669e735401198a20bb9e9915a92" member_type: VOTER } }
I20260812 06:16:29.018939 23044 sys_catalog.cc:458] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:29.018949 23046 sys_catalog.cc:458] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:29.019254 23050 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:29.020220 23050 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:29.020388 22747 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:29.022203 23050 catalog_manager.cc:1383] Generated new cluster ID: 8c1c8bb191ea46aa8334307331c551de
I20260812 06:16:29.022281 23050 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:29.069695 23050 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:29.070312 23050 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:29.082444 23050 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92: Generated new TSK 0
I20260812 06:16:29.082720 23050 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:29.085100 22747 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:29.087482 23063 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:29.087595 23070 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:29.087636 23065 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:29.087750 22747 server_base.cc:1061] running on GCE node
I20260812 06:16:29.088065 22747 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:29.088105 22747 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:29.088121 22747 hybrid_clock.cc:648] HybridClock initialized: now 1786515389088121 us; error 0 us; skew 500 ppm
I20260812 06:16:29.089020 22747 webserver.cc:533] Webserver started at http://127.22.54.193:43521/ using document root <none> and password file <none>
I20260812 06:16:29.089253 22747 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:29.089318 22747 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:29.089373 22747 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:29.089751 22747 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/instance:
uuid: "ede5088d81f24a81b740de11df35257b"
format_stamp: "Formatted at 2026-08-12 06:16:29 on dist-test-slave-9gcw"
I20260812 06:16:29.091325 22747 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:29.092321 23075 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:29.092587 22747 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:29.092695 22747 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root
uuid: "ede5088d81f24a81b740de11df35257b"
format_stamp: "Formatted at 2026-08-12 06:16:29 on dist-test-slave-9gcw"
I20260812 06:16:29.092792 22747 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-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:29.100736 22747 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:29.101114 22747 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:29.101480 22747 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:29.101964 22747 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:29.102030 22747 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:29.102092 22747 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:29.102128 22747 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:29.106732 22747 rpc_server.cc:307] RPC server started. Bound to: 127.22.54.193:45259
I20260812 06:16:29.107256 23150 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.54.193:45259 every 8 connection(s)
I20260812 06:16:29.118696 23151 heartbeater.cc:344] Connected to a master server at 127.22.54.254:33233
I20260812 06:16:29.118871 23151 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:29.119095 23151 heartbeater.cc:507] Master 127.22.54.254:33233 requested a full tablet report, sending...
I20260812 06:16:29.119918 23001 ts_manager.cc:194] Registered new tserver with Master: ede5088d81f24a81b740de11df35257b (127.22.54.193:45259)
I20260812 06:16:29.120828 23001 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37028
I20260812 06:16:29.120836 22747 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013484793s
I20260812 06:16:29.129462 23001 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37036:
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:29.139355 23109 tablet_service.cc:1511] Processing CreateTablet for tablet ee2a9f340cd54222b3b646b127966ff6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0903e9c236c747ff8a0e02a2bca32682]), partition=
I20260812 06:16:29.139760 23109 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ee2a9f340cd54222b3b646b127966ff6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:29.142105 23165 tablet_bootstrap.cc:492] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Bootstrap starting.
I20260812 06:16:29.143038 23165 tablet_bootstrap.cc:654] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:29.144330 23165 tablet_bootstrap.cc:492] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: No bootstrap required, opened a new log
I20260812 06:16:29.144426 23165 ts_tablet_manager.cc:1403] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:29.144917 23165 raft_consensus.cc:359] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede5088d81f24a81b740de11df35257b" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45259 } }
I20260812 06:16:29.145008 23165 raft_consensus.cc:385] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:29.145031 23165 raft_consensus.cc:740] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ede5088d81f24a81b740de11df35257b, State: Initialized, Role: FOLLOWER
I20260812 06:16:29.145226 23165 consensus_queue.cc:260] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [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: "ede5088d81f24a81b740de11df35257b" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45259 } }
I20260812 06:16:29.145303 23165 raft_consensus.cc:399] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:29.145363 23165 raft_consensus.cc:493] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:29.145418 23165 raft_consensus.cc:3060] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:29.146157 23165 raft_consensus.cc:515] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede5088d81f24a81b740de11df35257b" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45259 } }
I20260812 06:16:29.146276 23165 leader_election.cc:304] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [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: ede5088d81f24a81b740de11df35257b; no voters: 
I20260812 06:16:29.146508 23165 leader_election.cc:290] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:29.146759 23167 raft_consensus.cc:2804] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:29.146880 23151 heartbeater.cc:499] Master 127.22.54.254:33233 was elected leader, sending a full tablet report...
I20260812 06:16:29.146898 23167 raft_consensus.cc:697] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 1 LEADER]: Becoming Leader. State: Replica: ede5088d81f24a81b740de11df35257b, State: Running, Role: LEADER
I20260812 06:16:29.147115 23167 consensus_queue.cc:237] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [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: "ede5088d81f24a81b740de11df35257b" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45259 } }
I20260812 06:16:29.147192 23165 ts_tablet_manager.cc:1434] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:29.148856 23001 catalog_manager.cc:5719] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b reported cstate change: term changed from 0 to 1, leader changed from <none> to ede5088d81f24a81b740de11df35257b (127.22.54.193). New cstate: current_term: 1 leader_uuid: "ede5088d81f24a81b740de11df35257b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede5088d81f24a81b740de11df35257b" member_type: VOTER last_known_addr { host: "127.22.54.193" port: 45259 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:29.209071 22747 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.011s	sys 0.011s
I20260812 06:16:29.357995 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6): perf score=19.054940
I20260812 06:16:29.532676 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.174s	user 0.118s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1014,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46225,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:29.533437 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling LogGCOp(ee2a9f340cd54222b3b646b127966ff6): free 20290830 bytes of WAL
I20260812 06:16:29.533784 23081 log_reader.cc:385] T ee2a9f340cd54222b3b646b127966ff6: removed 2 log segments from log reader
I20260812 06:16:29.533850 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000001 (ops 1-6)
I20260812 06:16:29.533921 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000002 (ops 7-10)
I20260812 06:16:29.538709 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: LogGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:29.540763 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:29.566442 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.025s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.566979 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6): 16411391 bytes on disk
I20260812 06:16:29.567425 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:16:29.567834 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:29.578249 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.578843 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:29.745114 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.166s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":594,"lbm_read_time_us":10131,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26721,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":341,"threads_started":5,"update_count":2500}
I20260812 06:16:29.745761 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:29.799423 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.053s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23349,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.800024 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:29.815403 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.015s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.815960 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:29.978724 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.163s	user 0.128s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":10570,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28803,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:16:29.979590 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:30.045883 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.066s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.046422 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:30.056819 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.057367 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:30.236301 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.179s	user 0.126s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1322,"lbm_read_time_us":13276,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27819,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":2500}
I20260812 06:16:30.236907 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:30.292382 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.055s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23095,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.292999 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:30.304804 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.305548 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:30.488125 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.182s	user 0.134s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":13383,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28662,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:16:30.488777 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:30.546284 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.057s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22207,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.546830 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:30.558882 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.559434 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:30.750028 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.190s	user 0.122s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":14248,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31850,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:16:30.750730 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:30.811436 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.061s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22043,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.812067 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:30.823088 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.823524 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:30.870636 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.047s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1515,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1560,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:30.871345 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling LogGCOp(ee2a9f340cd54222b3b646b127966ff6): free 121006372 bytes of WAL
I20260812 06:16:30.871603 23081 log_reader.cc:385] T ee2a9f340cd54222b3b646b127966ff6: removed 12 log segments from log reader
I20260812 06:16:30.871673 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000003 (ops 11-15)
I20260812 06:16:30.871731 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000004 (ops 16-20)
I20260812 06:16:30.871795 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000005 (ops 21-25)
I20260812 06:16:30.871845 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000006 (ops 26-30)
I20260812 06:16:30.871888 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000007 (ops 31-35)
I20260812 06:16:30.871933 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000008 (ops 36-40)
I20260812 06:16:30.871978 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000009 (ops 41-45)
I20260812 06:16:30.872023 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000010 (ops 46-50)
I20260812 06:16:30.872068 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000011 (ops 51-54)
I20260812 06:16:30.872123 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000012 (ops 55-59)
I20260812 06:16:30.872166 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000013 (ops 60-64)
I20260812 06:16:30.872211 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000014 (ops 65-69)
I20260812 06:16:30.903154 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: LogGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:30.903681 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=3.181125
I20260812 06:16:30.918857 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:30.919317 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:30.939121 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.020s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4813,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.939951 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:31.179387 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.239s	user 0.174s	sys 0.062s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":527,"lbm_read_time_us":14487,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43481,"lbm_writes_lt_1ms":743,"mutex_wait_us":323,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:16:31.180271 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6): 473 bytes on disk
I20260812 06:16:31.180953 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:16:31.181507 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=18.063937
I20260812 06:16:31.245303 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.064s	user 0.051s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29267,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.245867 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:31.257481 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.257946 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:31.430940 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.173s	user 0.144s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1718,"lbm_read_time_us":12170,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37177,"lbm_writes_lt_1ms":643,"mutex_wait_us":636,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":50688,"update_count":3000}
I20260812 06:16:31.431493 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:31.486377 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.055s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24663,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.486970 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:31.504230 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.504739 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:31.681233 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.176s	user 0.121s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":399,"lbm_read_time_us":11484,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31739,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:16:31.682071 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:31.746533 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.064s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27523,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.747087 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:31.758505 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.759308 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:31.930826 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.171s	user 0.105s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":12007,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27452,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.931479 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:31.999270 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.068s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23752,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.999825 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.011480 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.011988 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:32.187801 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.176s	user 0.127s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":601,"lbm_read_time_us":13199,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28635,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:16:32.188522 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:32.245962 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.057s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22532,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:32.246555 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.257706 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.258889 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:32.298702 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.040s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1342,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2010,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:32.299484 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling LogGCOp(ee2a9f340cd54222b3b646b127966ff6): free 116849570 bytes of WAL
I20260812 06:16:32.299721 23081 log_reader.cc:385] T ee2a9f340cd54222b3b646b127966ff6: removed 12 log segments from log reader
I20260812 06:16:32.299783 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000015 (ops 70-74)
I20260812 06:16:32.299840 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000016 (ops 75-78)
I20260812 06:16:32.299898 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000017 (ops 79-83)
I20260812 06:16:32.299944 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000018 (ops 84-88)
I20260812 06:16:32.299983 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000019 (ops 89-93)
I20260812 06:16:32.300020 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000020 (ops 94-98)
I20260812 06:16:32.300060 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000021 (ops 99-102)
I20260812 06:16:32.300098 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000022 (ops 103-107)
I20260812 06:16:32.300148 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000023 (ops 108-112)
I20260812 06:16:32.300185 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000024 (ops 113-116)
I20260812 06:16:32.300225 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000025 (ops 117-121)
I20260812 06:16:32.300263 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000026 (ops 122-126)
I20260812 06:16:32.324143 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: LogGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:32.324545 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6): 447 bytes on disk
I20260812 06:16:32.324985 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.325861 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.347383 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.021s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.347951 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.358942 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.359555 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:32.619724 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.260s	user 0.193s	sys 0.051s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1851,"lbm_read_time_us":17311,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45360,"lbm_writes_lt_1ms":743,"mutex_wait_us":763,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:16:32.620841 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=18.063937
I20260812 06:16:32.689916 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.069s	user 0.056s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31239,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:32.690683 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.709600 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.019s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.710168 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:32.902747 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.192s	user 0.142s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":340,"lbm_read_time_us":13313,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34536,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:32.903307 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:32.957633 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.054s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23587,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.958158 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:32.974237 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.974910 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:33.148834 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.174s	user 0.148s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":370,"lbm_read_time_us":11907,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30897,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":2500}
I20260812 06:16:33.149519 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:33.191612 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.042s	user 0.019s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.192173 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:33.351534 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.159s	user 0.095s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":948,"lbm_read_time_us":11921,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28092,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25984,"update_count":2000}
I20260812 06:16:33.352212 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=10.126437
I20260812 06:16:33.388025 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15087,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:33.388553 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:33.405293 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.017s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.405824 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:33.541709 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.136s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":9810,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25848,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44160,"update_count":2000}
I20260812 06:16:33.542305 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=10.126437
I20260812 06:16:33.589633 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.047s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:33.590231 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:33.604403 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.604902 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:33.747414 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.142s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":10732,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27867,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29696,"update_count":2000}
I20260812 06:16:33.749513 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=10.126437
I20260812 06:16:33.793269 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.043s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16895,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:33.793840 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:33.805908 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.806643 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:33.840860 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushMRSOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1522,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1901,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:33.841672 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling LogGCOp(ee2a9f340cd54222b3b646b127966ff6): free 120100515 bytes of WAL
I20260812 06:16:33.841928 23081 log_reader.cc:385] T ee2a9f340cd54222b3b646b127966ff6: removed 12 log segments from log reader
I20260812 06:16:33.842002 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000027 (ops 127-130)
I20260812 06:16:33.842056 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000028 (ops 131-135)
I20260812 06:16:33.842113 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000029 (ops 136-140)
I20260812 06:16:33.842214 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000030 (ops 141-144)
I20260812 06:16:33.842260 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000031 (ops 145-149)
I20260812 06:16:33.842299 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000032 (ops 150-154)
I20260812 06:16:33.842340 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000033 (ops 155-159)
I20260812 06:16:33.842381 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000034 (ops 160-164)
I20260812 06:16:33.842422 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000035 (ops 165-169)
I20260812 06:16:33.842461 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000036 (ops 170-174)
I20260812 06:16:33.842499 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000037 (ops 175-178)
I20260812 06:16:33.842538 23081 log.cc:1079] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: Deleting log segment in path: /tmp/dist-test-task3avlVV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382996909-22747-0/minicluster-data/ts-0-root/wals/ee2a9f340cd54222b3b646b127966ff6/wal-000000038 (ops 179-183)
I20260812 06:16:33.869504 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: LogGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:33.869982 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6): 462 bytes on disk
I20260812 06:16:33.870508 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: UndoDeltaBlockGCOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:16:33.871204 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=3.181125
I20260812 06:16:33.883145 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4813,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:33.883708 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:33.893739 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3680,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.894570 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:34.084061 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.189s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":636,"lbm_read_time_us":12803,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38849,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":81664,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:16:34.084851 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=14.095187
I20260812 06:16:34.137055 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.052s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24351,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.137674 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6): perf score=2.188937
I20260812 06:16:34.154868 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: FlushDeltaMemStoresOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.017s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.155421 23152 maintenance_manager.cc:419] P ede5088d81f24a81b740de11df35257b: Scheduling MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6): perf score=1.000000
I20260812 06:16:34.221346 22747 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.012s	user 1.856s	sys 0.173s
I20260812 06:16:34.295675 22747 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:16:34.296216 22747 tablet_server.cc:179] TabletServer@127.22.54.193:0 shutting down...
I20260812 06:16:34.326331 23081 maintenance_manager.cc:643] P ede5088d81f24a81b740de11df35257b: MajorDeltaCompactionOp(ee2a9f340cd54222b3b646b127966ff6) complete. Timing: real 0.171s	user 0.123s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":9841,"lbm_reads_lt_1ms":560,"lbm_write_time_us":38265,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:16:34.327121 22747 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:34.327401 22747 tablet_replica.cc:333] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b: stopping tablet replica
I20260812 06:16:34.327543 22747 raft_consensus.cc:2243] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:34.327750 22747 raft_consensus.cc:2272] T ee2a9f340cd54222b3b646b127966ff6 P ede5088d81f24a81b740de11df35257b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:34.343751 22747 tablet_server.cc:196] TabletServer@127.22.54.193:0 shutdown complete.
I20260812 06:16:34.372496 22747 master.cc:562] Master@127.22.54.254:33233 shutting down...
I20260812 06:16:34.376237 22747 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:34.376439 22747 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:34.376528 22747 tablet_replica.cc:333] T 00000000000000000000000000000000 P ecad3669e735401198a20bb9e9915a92: stopping tablet replica
I20260812 06:16:34.388983 22747 master.cc:584] Master@127.22.54.254:33233 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5529 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11469 ms total)

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