[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:53.017091 19990 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.133.190:33675
I20260812 06:18:53.018090 19990 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:53.018704 19990 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:53.025023 19999 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:53.025070 19996 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.025166 19990 server_base.cc:1061] running on GCE node
W20260812 06:18:53.025414 20012 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.025862 19990 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.025974 19990 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:53.026011 19990 hybrid_clock.cc:648] HybridClock initialized: now 1786515533026009 us; error 0 us; skew 500 ppm
I20260812 06:18:53.027732 19990 webserver.cc:533] Webserver started at http://127.19.133.190:37949/ using document root <none> and password file <none>
I20260812 06:18:53.028290 19990 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.028353 19990 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.028586 19990 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.030282 19990 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/master-0-root/instance:
uuid: "e0ae18aaff2f4e57bac493a1866d4b88"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-gjw7"
I20260812 06:18:53.033825 19990 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:18:53.035784 20019 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.036756 19990 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:53.036862 19990 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/master-0-root
uuid: "e0ae18aaff2f4e57bac493a1866d4b88"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-gjw7"
I20260812 06:18:53.036947 19990 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:53.046337 19990 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.046854 19990 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:53.046993 19990 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.054046 20107 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.133.190:33675 every 8 connection(s)
I20260812 06:18:53.054051 19990 rpc_server.cc:307] RPC server started. Bound to: 127.19.133.190:33675
I20260812 06:18:53.056159 20108 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:53.061481 20108 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: Bootstrap starting.
I20260812 06:18:53.063711 20108 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.064567 20108 log.cc:826] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:53.066282 20108 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: No bootstrap required, opened a new log
I20260812 06:18:53.068975 20108 raft_consensus.cc:359] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER }
I20260812 06:18:53.069139 20108 raft_consensus.cc:385] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.069182 20108 raft_consensus.cc:740] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e0ae18aaff2f4e57bac493a1866d4b88, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.069772 20108 consensus_queue.cc:260] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [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: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER }
I20260812 06:18:53.069908 20108 raft_consensus.cc:399] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.069968 20108 raft_consensus.cc:493] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.070082 20108 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.071149 20108 raft_consensus.cc:515] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER }
I20260812 06:18:53.071588 20108 leader_election.cc:304] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [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: e0ae18aaff2f4e57bac493a1866d4b88; no voters: 
I20260812 06:18:53.071883 20108 leader_election.cc:290] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.071998 20115 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.072216 20115 raft_consensus.cc:697] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 1 LEADER]: Becoming Leader. State: Replica: e0ae18aaff2f4e57bac493a1866d4b88, State: Running, Role: LEADER
I20260812 06:18:53.072611 20115 consensus_queue.cc:237] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [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: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER }
I20260812 06:18:53.072853 20108 sys_catalog.cc:565] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:53.075141 19990 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:53.075380 20120 sys_catalog.cc:455] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e0ae18aaff2f4e57bac493a1866d4b88. Latest consensus state: current_term: 1 leader_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER } }
I20260812 06:18:53.075492 20119 sys_catalog.cc:455] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e0ae18aaff2f4e57bac493a1866d4b88" member_type: VOTER } }
I20260812 06:18:53.075498 20120 sys_catalog.cc:458] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.075670 20119 sys_catalog.cc:458] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [sys.catalog]: This master's current role is: LEADER
W20260812 06:18:53.078061 20156 catalog_manager.cc:1594] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:53.078137 20156 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:53.078199 20157 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:53.079113 20157 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:53.084678 20157 catalog_manager.cc:1383] Generated new cluster ID: d7c8700088784f10b7d8180f26714516
I20260812 06:18:53.084733 20157 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:53.102735 20157 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:53.103911 20157 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:53.110940 20157 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: Generated new TSK 0
I20260812 06:18:53.111655 20157 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:53.140563 19990 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:53.143164 20171 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.143230 19990 server_base.cc:1061] running on GCE node
W20260812 06:18:53.143175 20174 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:53.143378 20172 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.143621 19990 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.143672 19990 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:53.143693 19990 hybrid_clock.cc:648] HybridClock initialized: now 1786515533143693 us; error 0 us; skew 500 ppm
I20260812 06:18:53.144759 19990 webserver.cc:533] Webserver started at http://127.19.133.129:45847/ using document root <none> and password file <none>
I20260812 06:18:53.144925 19990 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.144981 19990 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.145057 19990 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.145489 19990 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/instance:
uuid: "2a2427e0781543f591f94685efe71357"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-gjw7"
I20260812 06:18:53.146914 19990 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:53.147836 20183 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.148044 19990 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:53.148113 19990 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root
uuid: "2a2427e0781543f591f94685efe71357"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-gjw7"
I20260812 06:18:53.148182 19990 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:53.165982 19990 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.166814 19990 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.167310 19990 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:53.168166 19990 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:53.168219 19990 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.168269 19990 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:53.168309 19990 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.174333 19990 rpc_server.cc:307] RPC server started. Bound to: 127.19.133.129:33083
I20260812 06:18:53.174487 20309 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.133.129:33083 every 8 connection(s)
I20260812 06:18:53.189946 20311 heartbeater.cc:344] Connected to a master server at 127.19.133.190:33675
I20260812 06:18:53.190213 20311 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:53.190727 20311 heartbeater.cc:507] Master 127.19.133.190:33675 requested a full tablet report, sending...
I20260812 06:18:53.192267 20046 ts_manager.cc:194] Registered new tserver with Master: 2a2427e0781543f591f94685efe71357 (127.19.133.129:33083)
I20260812 06:18:53.192840 19990 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017814198s
I20260812 06:18:53.193754 20046 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38844
I20260812 06:18:53.202173 20046 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38846:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:53.216789 20239 tablet_service.cc:1511] Processing CreateTablet for tablet ce35eb3f9ed841e887fca665dcf44c7c (DEFAULT_TABLE table=heavy-update-compaction-test [id=94f43f188a074b4e836b22f3df0fd466]), partition=
I20260812 06:18:53.217242 20239 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ce35eb3f9ed841e887fca665dcf44c7c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:53.219403 20332 tablet_bootstrap.cc:492] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Bootstrap starting.
I20260812 06:18:53.220814 20332 tablet_bootstrap.cc:654] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.222131 20332 tablet_bootstrap.cc:492] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: No bootstrap required, opened a new log
I20260812 06:18:53.222285 20332 ts_tablet_manager.cc:1403] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:53.222834 20332 raft_consensus.cc:359] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2427e0781543f591f94685efe71357" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 33083 } }
I20260812 06:18:53.222965 20332 raft_consensus.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.223012 20332 raft_consensus.cc:740] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2a2427e0781543f591f94685efe71357, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.223152 20332 consensus_queue.cc:260] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [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: "2a2427e0781543f591f94685efe71357" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 33083 } }
I20260812 06:18:53.223258 20332 raft_consensus.cc:399] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.223305 20332 raft_consensus.cc:493] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.223356 20332 raft_consensus.cc:3060] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.224272 20332 raft_consensus.cc:515] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2427e0781543f591f94685efe71357" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 33083 } }
I20260812 06:18:53.224426 20332 leader_election.cc:304] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [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: 2a2427e0781543f591f94685efe71357; no voters: 
I20260812 06:18:53.224640 20332 leader_election.cc:290] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.224727 20335 raft_consensus.cc:2804] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.224920 20335 raft_consensus.cc:697] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 1 LEADER]: Becoming Leader. State: Replica: 2a2427e0781543f591f94685efe71357, State: Running, Role: LEADER
I20260812 06:18:53.224984 20332 ts_tablet_manager.cc:1434] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:53.225147 20335 consensus_queue.cc:237] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [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: "2a2427e0781543f591f94685efe71357" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 33083 } }
I20260812 06:18:53.225318 20311 heartbeater.cc:499] Master 127.19.133.190:33675 was elected leader, sending a full tablet report...
I20260812 06:18:53.227592 20046 catalog_manager.cc:5719] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2a2427e0781543f591f94685efe71357 (127.19.133.129). New cstate: current_term: 1 leader_uuid: "2a2427e0781543f591f94685efe71357" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2427e0781543f591f94685efe71357" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 33083 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:53.288360 19990 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.021s	sys 0.004s
I20260812 06:18:53.425669 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=19.054940
I20260812 06:18:53.602545 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.176s	user 0.139s	sys 0.033s Metrics: {"bytes_written":14399713,"cfile_init":1,"compiler_manager_pool.queue_time_us":294,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1007,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43196,"lbm_writes_lt_1ms":808,"mutex_wait_us":173,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":187520,"thread_start_us":138,"threads_started":1,"update_count":1755}
I20260812 06:18:53.603698 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c): 16411398 bytes on disk
I20260812 06:18:53.604449 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.604871 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.196750
I20260812 06:18:53.620380 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3077038,"delete_count":0,"lbm_write_time_us":5146,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:18:53.620877 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c): free 20743880 bytes of WAL
I20260812 06:18:53.621198 20193 log_reader.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c: removed 2 log segments from log reader
I20260812 06:18:53.621330 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000001 (ops 1-6)
I20260812 06:18:53.621428 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000002 (ops 7-11)
I20260812 06:18:53.626215 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:53.626609 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.196750
I20260812 06:18:53.636708 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:18:53.637158 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:53.792791 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.155s	user 0.099s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774756,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":540,"lbm_read_time_us":10744,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25828,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":276,"threads_started":5,"update_count":2500}
I20260812 06:18:53.793380 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:53.828181 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.035s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13367,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.828667 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:53.838753 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.839223 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:53.976773 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.137s	user 0.105s	sys 0.025s 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":713,"lbm_read_time_us":7774,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27171,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":238,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.977281 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:54.023132 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.046s	user 0.023s	sys 0.014s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16368,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.023636 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:54.033635 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.034195 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.148736 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.114s	user 0.098s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":8682,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19770,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:18:54.149266 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:54.193365 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.044s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14732,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.193908 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:54.203558 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.204201 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.320528 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.116s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":7855,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22193,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:18:54.321084 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:54.365257 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.044s	user 0.023s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13475,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.365777 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:54.378834 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.379326 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.518757 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.139s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":164,"lbm_read_time_us":10808,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21722,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:18:54.519205 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:54.551106 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.032s	user 0.008s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12454,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.551573 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.649971 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.098s	user 0.062s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":962,"lbm_read_time_us":5827,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18548,"lbm_writes_lt_1ms":343,"mutex_wait_us":293,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.650465 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:54.687237 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.037s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15385,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.687680 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.724159 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.036s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1353,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1720,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:54.725004 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c): 447 bytes on disk
I20260812 06:18:54.725574 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":896}
I20260812 06:18:54.726018 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=3.181125
I20260812 06:18:54.742712 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6186,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:54.743114 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c): free 112239326 bytes of WAL
I20260812 06:18:54.743316 20193 log_reader.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c: removed 11 log segments from log reader
I20260812 06:18:54.743359 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000003 (ops 12-16)
I20260812 06:18:54.743387 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000004 (ops 17-21)
I20260812 06:18:54.743414 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000005 (ops 22-26)
I20260812 06:18:54.743445 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000006 (ops 27-31)
I20260812 06:18:54.743479 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000007 (ops 32-36)
I20260812 06:18:54.743512 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000008 (ops 37-40)
I20260812 06:18:54.743544 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000009 (ops 41-45)
I20260812 06:18:54.743577 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000010 (ops 46-50)
I20260812 06:18:54.743608 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000011 (ops 51-55)
I20260812 06:18:54.743640 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000012 (ops 56-60)
I20260812 06:18:54.743672 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000013 (ops 61-65)
I20260812 06:18:54.761838 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.019s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:54.762194 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:54.782243 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.020s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.782750 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:54.792619 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.793185 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:54.957863 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.164s	user 0.141s	sys 0.017s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":366,"lbm_read_time_us":10281,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32022,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:18:54.958284 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:55.004598 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.046s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16978,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.005098 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.015213 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.015816 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:55.156230 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.140s	user 0.100s	sys 0.035s 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":235,"lbm_read_time_us":8390,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27085,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28928,"update_count":2500}
I20260812 06:18:55.157135 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=12.110812
I20260812 06:18:55.193251 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.036s	user 0.022s	sys 0.011s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":15409,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:18:55.193861 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.196750
I20260812 06:18:55.205824 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3752,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:55.206348 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:55.343901 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.137s	user 0.093s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672249,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":373,"lbm_read_time_us":10406,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21435,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:18:55.344514 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=11.118625
I20260812 06:18:55.377671 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13877,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:55.378293 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.404546 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5435,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.405001 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.426882 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.022s	user 0.018s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.427595 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:55.592718 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.165s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":413,"lbm_read_time_us":12673,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26910,"lbm_writes_lt_1ms":543,"mutex_wait_us":251,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:55.593197 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=11.118625
I20260812 06:18:55.628235 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.035s	user 0.010s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13859,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:55.628686 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.650648 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.022s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4069,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.651190 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.660979 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3569,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.661624 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:55.817260 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.155s	user 0.098s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":136,"lbm_read_time_us":10185,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28636,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:18:55.817847 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:55.847276 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.029s	user 0.013s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":11996,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.847820 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:55.862280 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.862821 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:55.986629 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.124s	user 0.078s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":8882,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23959,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:18:55.987224 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=10.126437
I20260812 06:18:56.019133 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.032s	user 0.025s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13633,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:56.019727 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:56.073124 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.053s	user 0.030s	sys 0.002s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1402,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:56.073904 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c): free 112692381 bytes of WAL
I20260812 06:18:56.074232 20193 log_reader.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c: removed 11 log segments from log reader
I20260812 06:18:56.074292 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000014 (ops 66-70)
I20260812 06:18:56.074327 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000015 (ops 71-75)
I20260812 06:18:56.074357 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000016 (ops 76-80)
I20260812 06:18:56.074400 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000017 (ops 81-85)
I20260812 06:18:56.074433 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000018 (ops 86-90)
I20260812 06:18:56.074460 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000019 (ops 91-95)
I20260812 06:18:56.074488 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000020 (ops 96-100)
I20260812 06:18:56.074517 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000021 (ops 101-105)
I20260812 06:18:56.074549 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000022 (ops 106-110)
I20260812 06:18:56.074579 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000023 (ops 111-115)
I20260812 06:18:56.074606 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000024 (ops 116-120)
I20260812 06:18:56.098415 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:56.098820 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c): 462 bytes on disk
I20260812 06:18:56.099238 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:56.099932 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=6.157687
I20260812 06:18:56.125011 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.025s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10836,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:56.125499 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c): free 12017925 bytes of WAL
I20260812 06:18:56.125699 20193 log_reader.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c: removed 1 log segments from log reader
I20260812 06:18:56.125747 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000025 (ops 121-125)
I20260812 06:18:56.127568 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:56.127854 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:56.138872 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.139405 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:56.287655 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.148s	user 0.092s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":254,"lbm_read_time_us":10134,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29777,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:18:56.288133 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:56.333755 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.045s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19744,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.334255 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:56.348687 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.349225 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:56.504776 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.155s	user 0.119s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":9382,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26788,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":69376,"update_count":2500}
I20260812 06:18:56.505487 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:56.551047 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.045s	user 0.011s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.551573 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:56.696960 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.145s	user 0.100s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":148,"lbm_read_time_us":10032,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22043,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:18:56.697525 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:56.745509 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.048s	user 0.034s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18704,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.746063 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:56.760694 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.761240 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:56.938243 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.177s	user 0.103s	sys 0.058s 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":246,"lbm_read_time_us":10284,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27135,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:56.938812 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:56.984018 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19549,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.984584 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:56.996906 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.997468 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:57.151894 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.154s	user 0.096s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":984,"lbm_read_time_us":10543,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26933,"lbm_writes_lt_1ms":543,"mutex_wait_us":484,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:57.152478 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:57.207494 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.055s	user 0.020s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27736,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.207988 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:57.219127 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.219559 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:57.356417 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.137s	user 0.106s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":8978,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26019,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:57.356922 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:57.402443 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16398,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.402969 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:57.417582 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.014s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.418128 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:57.443415 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushMRSOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.025s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1161,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1335,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:57.444103 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c): free 124710550 bytes of WAL
I20260812 06:18:57.444355 20193 log_reader.cc:385] T ce35eb3f9ed841e887fca665dcf44c7c: removed 12 log segments from log reader
I20260812 06:18:57.444418 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000026 (ops 126-130)
I20260812 06:18:57.444464 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000027 (ops 131-135)
I20260812 06:18:57.444494 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000028 (ops 136-140)
I20260812 06:18:57.444525 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000029 (ops 141-145)
I20260812 06:18:57.444556 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000030 (ops 146-150)
I20260812 06:18:57.444588 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000031 (ops 151-155)
I20260812 06:18:57.444615 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000032 (ops 156-160)
I20260812 06:18:57.444643 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000033 (ops 161-165)
I20260812 06:18:57.444671 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000034 (ops 166-170)
I20260812 06:18:57.444706 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000035 (ops 171-175)
I20260812 06:18:57.444737 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000036 (ops 176-180)
I20260812 06:18:57.444765 20193 log.cc:1079] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/ce35eb3f9ed841e887fca665dcf44c7c/wal-000000037 (ops 181-185)
I20260812 06:18:57.470444 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: LogGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:57.470813 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c): 482 bytes on disk
I20260812 06:18:57.471206 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: UndoDeltaBlockGCOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.471798 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=3.181125
I20260812 06:18:57.485321 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.013s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4128,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:57.485770 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:57.495515 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3586,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:57.495962 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:57.711402 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.215s	user 0.157s	sys 0.051s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":218,"lbm_read_time_us":14722,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35240,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":103424,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:18:57.712004 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=14.095187
I20260812 06:18:57.769613 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.057s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23901,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.770059 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:57.792748 19990 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.504s	user 1.667s	sys 0.105s
I20260812 06:18:57.794139 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.024s	user 0.005s	sys 0.005s 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:18:57.794565 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=2.188937
I20260812 06:18:57.803874 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: FlushDeltaMemStoresOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.804302 20313 maintenance_manager.cc:419] P 2a2427e0781543f591f94685efe71357: Scheduling MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c): perf score=1.000000
I20260812 06:18:57.864089 19990 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.001s	sys 0.000s
I20260812 06:18:57.864665 19990 tablet_server.cc:179] TabletServer@127.19.133.129:0 shutting down...
I20260812 06:18:57.946635 20193 maintenance_manager.cc:643] P 2a2427e0781543f591f94685efe71357: MajorDeltaCompactionOp(ce35eb3f9ed841e887fca665dcf44c7c) complete. Timing: real 0.142s	user 0.107s	sys 0.034s Metrics: {"cfile_cache_hit":203,"cfile_cache_hit_bytes":8250013,"cfile_cache_miss":430,"cfile_cache_miss_bytes":20627210,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":320,"lbm_read_time_us":7763,"lbm_reads_lt_1ms":462,"lbm_write_time_us":26965,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":37248,"update_count":3000}
I20260812 06:18:57.947302 19990 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:57.947715 19990 tablet_replica.cc:333] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357: stopping tablet replica
I20260812 06:18:57.947990 19990 raft_consensus.cc:2243] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:57.948240 19990 raft_consensus.cc:2272] T ce35eb3f9ed841e887fca665dcf44c7c P 2a2427e0781543f591f94685efe71357 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:57.969985 19990 tablet_server.cc:196] TabletServer@127.19.133.129:0 shutdown complete.
I20260812 06:18:57.999009 19990 master.cc:562] Master@127.19.133.190:33675 shutting down...
I20260812 06:18:58.002281 19990 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.002442 19990 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.002494 19990 tablet_replica.cc:333] T 00000000000000000000000000000000 P e0ae18aaff2f4e57bac493a1866d4b88: stopping tablet replica
I20260812 06:18:58.014472 19990 master.cc:584] Master@127.19.133.190:33675 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5070 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:58.101437 19990 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.133.190:36019
I20260812 06:18:58.101805 19990 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:58.103612 20378 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:58.103612 20370 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:58.103739 20371 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:58.103840 19990 server_base.cc:1061] running on GCE node
I20260812 06:18:58.103976 19990 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:58.104015 19990 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:58.104040 19990 hybrid_clock.cc:648] HybridClock initialized: now 1786515538104040 us; error 0 us; skew 500 ppm
I20260812 06:18:58.104780 19990 webserver.cc:533] Webserver started at http://127.19.133.190:34847/ using document root <none> and password file <none>
I20260812 06:18:58.104919 19990 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:58.104966 19990 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:58.105037 19990 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:58.105458 19990 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/master-0-root/instance:
uuid: "adeafa9b0eb64a32b026d44a4885aa0c"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-gjw7"
I20260812 06:18:58.106796 19990 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:58.107611 20390 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.107824 19990 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:58.107885 19990 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/master-0-root
uuid: "adeafa9b0eb64a32b026d44a4885aa0c"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-gjw7"
I20260812 06:18:58.107949 19990 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:58.117154 19990 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:58.117551 19990 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:58.121445 19990 rpc_server.cc:307] RPC server started. Bound to: 127.19.133.190:36019
I20260812 06:18:58.124743 20496 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.133.190:36019 every 8 connection(s)
I20260812 06:18:58.125154 20498 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:58.126940 20498 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c: Bootstrap starting.
I20260812 06:18:58.127647 20498 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:58.128515 20498 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c: No bootstrap required, opened a new log
I20260812 06:18:58.128854 20498 raft_consensus.cc:359] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER }
I20260812 06:18:58.128930 20498 raft_consensus.cc:385] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:58.128957 20498 raft_consensus.cc:740] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: adeafa9b0eb64a32b026d44a4885aa0c, State: Initialized, Role: FOLLOWER
I20260812 06:18:58.129055 20498 consensus_queue.cc:260] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [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: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER }
I20260812 06:18:58.129110 20498 raft_consensus.cc:399] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:58.129142 20498 raft_consensus.cc:493] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:58.129182 20498 raft_consensus.cc:3060] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:58.129850 20498 raft_consensus.cc:515] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER }
I20260812 06:18:58.129962 20498 leader_election.cc:304] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [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: adeafa9b0eb64a32b026d44a4885aa0c; no voters: 
I20260812 06:18:58.130100 20498 leader_election.cc:290] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:58.130191 20503 raft_consensus.cc:2804] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:58.130364 20503 raft_consensus.cc:697] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 1 LEADER]: Becoming Leader. State: Replica: adeafa9b0eb64a32b026d44a4885aa0c, State: Running, Role: LEADER
I20260812 06:18:58.130527 20498 sys_catalog.cc:565] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:58.130507 20503 consensus_queue.cc:237] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [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: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER }
I20260812 06:18:58.130926 20506 sys_catalog.cc:455] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER } }
I20260812 06:18:58.130944 20509 sys_catalog.cc:455] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [sys.catalog]: SysCatalogTable state changed. Reason: New leader adeafa9b0eb64a32b026d44a4885aa0c. Latest consensus state: current_term: 1 leader_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adeafa9b0eb64a32b026d44a4885aa0c" member_type: VOTER } }
I20260812 06:18:58.131103 20509 sys_catalog.cc:458] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:58.131088 20506 sys_catalog.cc:458] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:58.131623 20515 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:58.132349 20515 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:58.132560 19990 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:58.134029 20515 catalog_manager.cc:1383] Generated new cluster ID: c4ec6a896d804317a4a664025c0552c2
I20260812 06:18:58.134083 20515 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:58.139235 20515 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:58.139698 20515 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:58.147687 20515 catalog_manager.cc:6092] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c: Generated new TSK 0
I20260812 06:18:58.147819 20515 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:58.164865 19990 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:58.166898 20552 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:58.166963 19990 server_base.cc:1061] running on GCE node
W20260812 06:18:58.167021 20546 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:58.167057 20550 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:58.167349 19990 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:58.167392 19990 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:58.167407 19990 hybrid_clock.cc:648] HybridClock initialized: now 1786515538167407 us; error 0 us; skew 500 ppm
I20260812 06:18:58.168160 19990 webserver.cc:533] Webserver started at http://127.19.133.129:40635/ using document root <none> and password file <none>
I20260812 06:18:58.168289 19990 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:58.168329 19990 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:58.168382 19990 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:58.168737 19990 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/instance:
uuid: "d1ab27c96e55461c94e2c9cd8bc9df38"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-gjw7"
I20260812 06:18:58.170125 19990 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:58.170939 20560 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.171171 19990 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:58.171242 19990 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root
uuid: "d1ab27c96e55461c94e2c9cd8bc9df38"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-gjw7"
I20260812 06:18:58.171308 19990 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:58.184784 19990 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:58.185139 19990 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:58.185469 19990 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:58.185920 19990 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:58.185958 19990 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.186000 19990 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:58.186029 19990 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.189898 19990 rpc_server.cc:307] RPC server started. Bound to: 127.19.133.129:42851
I20260812 06:18:58.189944 20695 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.133.129:42851 every 8 connection(s)
I20260812 06:18:58.196770 20696 heartbeater.cc:344] Connected to a master server at 127.19.133.190:36019
I20260812 06:18:58.196856 20696 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:58.197075 20696 heartbeater.cc:507] Master 127.19.133.190:36019 requested a full tablet report, sending...
I20260812 06:18:58.197666 20429 ts_manager.cc:194] Registered new tserver with Master: d1ab27c96e55461c94e2c9cd8bc9df38 (127.19.133.129:42851)
I20260812 06:18:58.197989 19990 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007690585s
I20260812 06:18:58.198362 20429 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41558
I20260812 06:18:58.204358 20429 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41566:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:58.212532 20609 tablet_service.cc:1511] Processing CreateTablet for tablet 8fe5ef599cbf48008b61e02909ed0814 (DEFAULT_TABLE table=heavy-update-compaction-test [id=138892d5cc854314adef1a2c8a22defc]), partition=
I20260812 06:18:58.212769 20609 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8fe5ef599cbf48008b61e02909ed0814. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:58.214547 20722 tablet_bootstrap.cc:492] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Bootstrap starting.
I20260812 06:18:58.215430 20722 tablet_bootstrap.cc:654] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:58.216293 20722 tablet_bootstrap.cc:492] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: No bootstrap required, opened a new log
I20260812 06:18:58.216365 20722 ts_tablet_manager.cc:1403] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:58.216722 20722 raft_consensus.cc:359] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1ab27c96e55461c94e2c9cd8bc9df38" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 42851 } }
I20260812 06:18:58.216804 20722 raft_consensus.cc:385] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:58.216838 20722 raft_consensus.cc:740] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d1ab27c96e55461c94e2c9cd8bc9df38, State: Initialized, Role: FOLLOWER
I20260812 06:18:58.216964 20722 consensus_queue.cc:260] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [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: "d1ab27c96e55461c94e2c9cd8bc9df38" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 42851 } }
I20260812 06:18:58.217033 20722 raft_consensus.cc:399] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:58.217069 20722 raft_consensus.cc:493] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:58.217116 20722 raft_consensus.cc:3060] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:58.217959 20722 raft_consensus.cc:515] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1ab27c96e55461c94e2c9cd8bc9df38" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 42851 } }
I20260812 06:18:58.218104 20722 leader_election.cc:304] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [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: d1ab27c96e55461c94e2c9cd8bc9df38; no voters: 
I20260812 06:18:58.218292 20722 leader_election.cc:290] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:58.218384 20724 raft_consensus.cc:2804] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:58.218591 20722 ts_tablet_manager.cc:1434] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:58.218604 20724 raft_consensus.cc:697] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 1 LEADER]: Becoming Leader. State: Replica: d1ab27c96e55461c94e2c9cd8bc9df38, State: Running, Role: LEADER
I20260812 06:18:58.218604 20696 heartbeater.cc:499] Master 127.19.133.190:36019 was elected leader, sending a full tablet report...
I20260812 06:18:58.218791 20724 consensus_queue.cc:237] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [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: "d1ab27c96e55461c94e2c9cd8bc9df38" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 42851 } }
I20260812 06:18:58.219981 20429 catalog_manager.cc:5719] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 reported cstate change: term changed from 0 to 1, leader changed from <none> to d1ab27c96e55461c94e2c9cd8bc9df38 (127.19.133.129). New cstate: current_term: 1 leader_uuid: "d1ab27c96e55461c94e2c9cd8bc9df38" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1ab27c96e55461c94e2c9cd8bc9df38" member_type: VOTER last_known_addr { host: "127.19.133.129" port: 42851 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:58.270617 19990 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.017s	sys 0.004s
I20260812 06:18:58.440879 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814): perf score=23.023690
I20260812 06:18:58.604889 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.164s	user 0.108s	sys 0.050s Metrics: {"bytes_written":16409901,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":894,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41209,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":2000}
I20260812 06:18:58.605551 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling LogGCOp(8fe5ef599cbf48008b61e02909ed0814): free 20743880 bytes of WAL
I20260812 06:18:58.605773 20566 log_reader.cc:385] T 8fe5ef599cbf48008b61e02909ed0814: removed 2 log segments from log reader
I20260812 06:18:58.605820 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000001 (ops 1-6)
I20260812 06:18:58.605860 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000002 (ops 7-11)
I20260812 06:18:58.609469 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: LogGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:58.609741 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:58.622099 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.622514 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:58.792351 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.170s	user 0.132s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":11567,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28445,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":288,"threads_started":5,"update_count":2500}
I20260812 06:18:58.792855 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814): 20513816 bytes on disk
I20260812 06:18:58.793260 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.793684 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:18:58.853789 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.060s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19666,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.854295 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:58.868897 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.869378 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:59.048254 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.179s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":653,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28099,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:59.048748 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:18:59.106683 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.058s	user 0.033s	sys 0.018s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22587,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.107244 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.123003 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.123462 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:59.302186 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.179s	user 0.118s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":894,"lbm_read_time_us":12428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29817,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2500}
I20260812 06:18:59.302729 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:18:59.354557 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.052s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17954,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.355101 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.371304 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6393,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.371744 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:59.535184 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.163s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":11450,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25590,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:59.535647 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=11.118625
I20260812 06:18:59.567822 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13546,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:59.568571 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.580986 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":93,"mutex_wait_us":27,"reinsert_count":0,"update_count":450}
I20260812 06:18:59.581539 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:59.739076 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.157s	user 0.080s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":7351,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24264,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2000}
I20260812 06:18:59.739615 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:18:59.788285 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.048s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18997,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:59.788770 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.798182 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.798738 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:18:59.825407 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.026s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1369,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:59.826040 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling LogGCOp(8fe5ef599cbf48008b61e02909ed0814): free 121006425 bytes of WAL
I20260812 06:18:59.826270 20566 log_reader.cc:385] T 8fe5ef599cbf48008b61e02909ed0814: removed 12 log segments from log reader
I20260812 06:18:59.826318 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000003 (ops 12-16)
I20260812 06:18:59.826346 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000004 (ops 17-21)
I20260812 06:18:59.826366 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000005 (ops 22-26)
I20260812 06:18:59.826398 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000006 (ops 27-31)
I20260812 06:18:59.826432 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000007 (ops 32-36)
I20260812 06:18:59.826464 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000008 (ops 37-41)
I20260812 06:18:59.826495 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000009 (ops 42-46)
I20260812 06:18:59.826526 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000010 (ops 47-51)
I20260812 06:18:59.826558 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000011 (ops 52-56)
I20260812 06:18:59.826588 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000012 (ops 57-60)
I20260812 06:18:59.826619 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000013 (ops 61-65)
I20260812 06:18:59.826649 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000014 (ops 66-70)
I20260812 06:18:59.846127 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: LogGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:59.846487 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.863437 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.017s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.863909 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814): 463 bytes on disk
I20260812 06:18:59.864298 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:59.864774 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:18:59.879146 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.879647 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:00.110519 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.229s	user 0.158s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":493,"lbm_read_time_us":14532,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33376,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:00.111096 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=18.063937
I20260812 06:19:00.177491 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.066s	user 0.027s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25294,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:00.178083 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:00.192332 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.192777 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:00.390545 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.198s	user 0.130s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14440,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29786,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":36352,"update_count":3000}
I20260812 06:19:00.391193 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:00.450664 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.059s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20515,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.451148 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:00.460928 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.461643 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:00.615854 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.154s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":728,"lbm_read_time_us":10557,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25176,"lbm_writes_lt_1ms":543,"mutex_wait_us":217,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:19:00.616431 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:00.667919 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.051s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18658,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.668463 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:00.681357 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.681951 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:00.865083 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.181s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":307,"lbm_read_time_us":13204,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30990,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:19:00.865680 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:00.924908 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.059s	user 0.025s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25364,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:00.925607 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:00.937670 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.938138 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:01.094077 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.156s	user 0.104s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":528,"lbm_read_time_us":9508,"lbm_reads_lt_1ms":568,"lbm_write_time_us":23897,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:19:01.094676 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:01.145259 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.050s	user 0.024s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20863,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.145833 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:01.155884 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.156369 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:01.185827 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.029s	user 0.024s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1111,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1277,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:01.186481 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:01.352458 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.166s	user 0.112s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":11430,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26614,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:19:01.353005 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling LogGCOp(8fe5ef599cbf48008b61e02909ed0814): free 120100323 bytes of WAL
I20260812 06:19:01.353258 20566 log_reader.cc:385] T 8fe5ef599cbf48008b61e02909ed0814: removed 12 log segments from log reader
I20260812 06:19:01.353363 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000015 (ops 71-74)
I20260812 06:19:01.353411 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000016 (ops 75-79)
I20260812 06:19:01.353434 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000017 (ops 80-84)
I20260812 06:19:01.353485 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000018 (ops 85-89)
I20260812 06:19:01.353515 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000019 (ops 90-94)
I20260812 06:19:01.353560 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000020 (ops 95-98)
I20260812 06:19:01.353590 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000021 (ops 99-103)
I20260812 06:19:01.353634 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000022 (ops 104-108)
I20260812 06:19:01.353663 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000023 (ops 109-112)
I20260812 06:19:01.353713 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000024 (ops 113-117)
I20260812 06:19:01.353745 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000025 (ops 118-122)
I20260812 06:19:01.353790 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000026 (ops 123-127)
I20260812 06:19:01.375734 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: LogGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:19:01.376139 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=15.087375
I20260812 06:19:01.442020 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.066s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21242,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:01.442458 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814): 447 bytes on disk
I20260812 06:19:01.442827 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:01.443289 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=6.157687
I20260812 06:19:01.460431 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":6852,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:01.461004 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:01.643132 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.182s	user 0.107s	sys 0.074s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":641,"lbm_read_time_us":14219,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29221,"lbm_writes_lt_1ms":643,"mutex_wait_us":303,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":3000}
I20260812 06:19:01.643766 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:01.699012 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.055s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20492,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.699542 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:01.713709 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.714306 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:01.878330 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.164s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":11079,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24809,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56832,"update_count":2500}
I20260812 06:19:01.878906 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:01.935680 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.057s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22535,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.936388 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:01.947288 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.947746 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:02.113517 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.166s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":9941,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27377,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68224,"update_count":2500}
I20260812 06:19:02.114001 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:02.160473 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.046s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19734,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.160988 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:02.186535 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.025s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.187354 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:02.355821 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.168s	user 0.115s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1157,"lbm_read_time_us":11092,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27700,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.356369 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:02.409389 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.053s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22399,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.409886 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:02.426138 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.426632 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:02.585924 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.159s	user 0.104s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":10513,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28741,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:02.586529 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:02.634757 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20607,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.635257 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:02.645962 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.646397 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:02.672843 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushMRSOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1246,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1396,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:02.673506 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling LogGCOp(8fe5ef599cbf48008b61e02909ed0814): free 124710507 bytes of WAL
I20260812 06:19:02.673710 20566 log_reader.cc:385] T 8fe5ef599cbf48008b61e02909ed0814: removed 12 log segments from log reader
I20260812 06:19:02.673755 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000027 (ops 128-132)
I20260812 06:19:02.673786 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000028 (ops 133-137)
I20260812 06:19:02.673818 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000029 (ops 138-142)
I20260812 06:19:02.673851 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000030 (ops 143-147)
I20260812 06:19:02.673884 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000031 (ops 148-152)
I20260812 06:19:02.673916 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000032 (ops 153-157)
I20260812 06:19:02.673949 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000033 (ops 158-162)
I20260812 06:19:02.673981 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000034 (ops 163-167)
I20260812 06:19:02.674002 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000035 (ops 168-172)
I20260812 06:19:02.674019 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000036 (ops 173-177)
I20260812 06:19:02.674041 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000037 (ops 178-182)
I20260812 06:19:02.674063 20566 log.cc:1079] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: Deleting log segment in path: /tmp/dist-test-taskePZImC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533006205-19990-0/minicluster-data/ts-0-root/wals/8fe5ef599cbf48008b61e02909ed0814/wal-000000038 (ops 183-187)
I20260812 06:19:02.697525 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: LogGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.024s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:19:02.698056 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=3.181125
I20260812 06:19:02.719908 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.022s	user 0.005s	sys 0.014s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:02.720413 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814): 482 bytes on disk
I20260812 06:19:02.720845 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: UndoDeltaBlockGCOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:02.721421 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:02.730635 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3518,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:02.731000 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:02.942102 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.211s	user 0.140s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4732,"dirs.run_cpu_time_us":483,"dirs.run_wall_time_us":2734,"lbm_read_time_us":15481,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33198,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":3500}
I20260812 06:19:02.942798 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=14.095187
I20260812 06:19:02.957887 19990 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.687s	user 1.673s	sys 0.232s
I20260812 06:19:02.986092 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.043s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21239,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:02.986613 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814): perf score=2.188937
I20260812 06:19:02.997460 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: FlushDeltaMemStoresOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.997892 20697 maintenance_manager.cc:419] P d1ab27c96e55461c94e2c9cd8bc9df38: Scheduling MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814): perf score=1.000000
I20260812 06:19:03.004345 19990 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.046s	user 0.001s	sys 0.000s
I20260812 06:19:03.004791 19990 tablet_server.cc:179] TabletServer@127.19.133.129:0 shutting down...
I20260812 06:19:03.134112 20566 maintenance_manager.cc:643] P d1ab27c96e55461c94e2c9cd8bc9df38: MajorDeltaCompactionOp(8fe5ef599cbf48008b61e02909ed0814) complete. Timing: real 0.136s	user 0.104s	sys 0.031s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4303385,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512302,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":7963,"lbm_reads_lt_1ms":518,"lbm_write_time_us":21523,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:03.134764 19990 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:03.134999 19990 tablet_replica.cc:333] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38: stopping tablet replica
I20260812 06:19:03.135115 19990 raft_consensus.cc:2243] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.135272 19990 raft_consensus.cc:2272] T 8fe5ef599cbf48008b61e02909ed0814 P d1ab27c96e55461c94e2c9cd8bc9df38 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.140458 19990 tablet_server.cc:196] TabletServer@127.19.133.129:0 shutdown complete.
I20260812 06:19:03.179057 19990 master.cc:562] Master@127.19.133.190:36019 shutting down...
I20260812 06:19:03.182672 19990 raft_consensus.cc:2243] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.182878 19990 raft_consensus.cc:2272] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.182955 19990 tablet_replica.cc:333] T 00000000000000000000000000000000 P adeafa9b0eb64a32b026d44a4885aa0c: stopping tablet replica
I20260812 06:19:03.195122 19990 master.cc:584] Master@127.19.133.190:36019 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5183 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10255 ms total)

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