[==========] 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:17:05.673455 11127 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.221.254:42959
I20260812 06:17:05.674690 11127 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:17:05.675422 11127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.684129 11135 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:17:05.684263 11127 server_base.cc:1061] running on GCE node
W20260812 06:17:05.684465 11134 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:17:05.684552 11137 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:17:05.685159 11127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.685297 11127 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:17:05.685345 11127 hybrid_clock.cc:648] HybridClock initialized: now 1786515425685342 us; error 0 us; skew 500 ppm
I20260812 06:17:05.687749 11127 webserver.cc:533] Webserver started at http://127.10.221.254:35061/ using document root <none> and password file <none>
I20260812 06:17:05.688398 11127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.688494 11127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.688776 11127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.691097 11127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/master-0-root/instance:
uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-dhph"
I20260812 06:17:05.695542 11127 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:17:05.698493 11146 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:17:05.700362 11127 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:05.700562 11127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/master-0-root
uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-dhph"
I20260812 06:17:05.700784 11127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-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:17:05.715502 11127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.716243 11127 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:17:05.716445 11127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.725299 11127 rpc_server.cc:307] RPC server started. Bound to: 127.10.221.254:42959
I20260812 06:17:05.725327 11206 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.221.254:42959 every 8 connection(s)
I20260812 06:17:05.727865 11208 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:17:05.734685 11208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: Bootstrap starting.
I20260812 06:17:05.737380 11208 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.738492 11208 log.cc:826] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:05.740797 11208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: No bootstrap required, opened a new log
I20260812 06:17:05.744071 11208 raft_consensus.cc:359] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER }
I20260812 06:17:05.744277 11208 raft_consensus.cc:385] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.744324 11208 raft_consensus.cc:740] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bcbfe2fbd0b841f88b7fd6cff8918f4b, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.744944 11208 consensus_queue.cc:260] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [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: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER }
I20260812 06:17:05.745093 11208 raft_consensus.cc:399] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.745141 11208 raft_consensus.cc:493] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.745229 11208 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.746124 11208 raft_consensus.cc:515] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER }
I20260812 06:17:05.746769 11208 leader_election.cc:304] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [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: bcbfe2fbd0b841f88b7fd6cff8918f4b; no voters: 
I20260812 06:17:05.747324 11208 leader_election.cc:290] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.747673 11211 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.747968 11211 raft_consensus.cc:697] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 1 LEADER]: Becoming Leader. State: Replica: bcbfe2fbd0b841f88b7fd6cff8918f4b, State: Running, Role: LEADER
I20260812 06:17:05.748490 11208 sys_catalog.cc:565] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:05.748544 11211 consensus_queue.cc:237] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [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: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER }
I20260812 06:17:05.751637 11212 sys_catalog.cc:455] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER } }
I20260812 06:17:05.751655 11213 sys_catalog.cc:455] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [sys.catalog]: SysCatalogTable state changed. Reason: New leader bcbfe2fbd0b841f88b7fd6cff8918f4b. Latest consensus state: current_term: 1 leader_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bcbfe2fbd0b841f88b7fd6cff8918f4b" member_type: VOTER } }
I20260812 06:17:05.751935 11212 sys_catalog.cc:458] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.751940 11213 sys_catalog.cc:458] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.752032 11127 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:05.754421 11226 catalog_manager.cc:1594] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:05.754544 11226 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:05.754650 11227 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:05.755704 11227 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:05.761549 11227 catalog_manager.cc:1383] Generated new cluster ID: 7ce1cf7785574f2bb8d087a2fb0202f5
I20260812 06:17:05.761646 11227 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:05.774190 11227 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:05.775163 11227 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:05.783089 11227 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: Generated new TSK 0
I20260812 06:17:05.783847 11227 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:05.817262 11127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.821457 11234 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:17:05.821482 11232 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:17:05.821548 11231 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:17:05.821897 11127 server_base.cc:1061] running on GCE node
I20260812 06:17:05.822146 11127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.822206 11127 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:17:05.822244 11127 hybrid_clock.cc:648] HybridClock initialized: now 1786515425822242 us; error 0 us; skew 500 ppm
I20260812 06:17:05.823400 11127 webserver.cc:533] Webserver started at http://127.10.221.193:34899/ using document root <none> and password file <none>
I20260812 06:17:05.823599 11127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.823678 11127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.823767 11127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.824234 11127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/instance:
uuid: "b845cf9789484349a078d63f094a230a"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-dhph"
I20260812 06:17:05.826040 11127 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:05.827303 11240 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:17:05.827618 11127 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.827719 11127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root
uuid: "b845cf9789484349a078d63f094a230a"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-dhph"
I20260812 06:17:05.827812 11127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-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:17:05.850008 11127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.850965 11127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.851580 11127 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:05.852577 11127 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:05.852638 11127 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.852689 11127 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:05.852705 11127 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.867913 11127 rpc_server.cc:307] RPC server started. Bound to: 127.10.221.193:35013
I20260812 06:17:05.867977 11313 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.221.193:35013 every 8 connection(s)
I20260812 06:17:05.888501 11314 heartbeater.cc:344] Connected to a master server at 127.10.221.254:42959
I20260812 06:17:05.888832 11314 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:05.889438 11314 heartbeater.cc:507] Master 127.10.221.254:42959 requested a full tablet report, sending...
I20260812 06:17:05.891881 11163 ts_manager.cc:194] Registered new tserver with Master: b845cf9789484349a078d63f094a230a (127.10.221.193:35013)
I20260812 06:17:05.892046 11127 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.023271208s
I20260812 06:17:05.893934 11163 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54130
I20260812 06:17:05.906291 11163 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54140:
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:17:05.928143 11270 tablet_service.cc:1511] Processing CreateTablet for tablet 098a314d975e4ecc88eefd5d6ffc0386 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4581d80e13f1451ea5f3f9273e80c41d]), partition=
I20260812 06:17:05.928884 11270 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 098a314d975e4ecc88eefd5d6ffc0386. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:05.933395 11327 tablet_bootstrap.cc:492] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Bootstrap starting.
I20260812 06:17:05.935514 11327 tablet_bootstrap.cc:654] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.937318 11327 tablet_bootstrap.cc:492] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: No bootstrap required, opened a new log
I20260812 06:17:05.937492 11327 ts_tablet_manager.cc:1403] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:17:05.938158 11327 raft_consensus.cc:359] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b845cf9789484349a078d63f094a230a" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 35013 } }
I20260812 06:17:05.938333 11327 raft_consensus.cc:385] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.938444 11327 raft_consensus.cc:740] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b845cf9789484349a078d63f094a230a, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.938714 11327 consensus_queue.cc:260] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [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: "b845cf9789484349a078d63f094a230a" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 35013 } }
I20260812 06:17:05.938853 11327 raft_consensus.cc:399] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.938907 11327 raft_consensus.cc:493] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.938962 11327 raft_consensus.cc:3060] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.940670 11327 raft_consensus.cc:515] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b845cf9789484349a078d63f094a230a" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 35013 } }
I20260812 06:17:05.941048 11327 leader_election.cc:304] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [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: b845cf9789484349a078d63f094a230a; no voters: 
I20260812 06:17:05.941372 11327 leader_election.cc:290] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.941737 11329 raft_consensus.cc:2804] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.941857 11327 ts_tablet_manager.cc:1434] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Time spent starting tablet: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:17:05.942198 11329 raft_consensus.cc:697] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 1 LEADER]: Becoming Leader. State: Replica: b845cf9789484349a078d63f094a230a, State: Running, Role: LEADER
I20260812 06:17:05.942484 11314 heartbeater.cc:499] Master 127.10.221.254:42959 was elected leader, sending a full tablet report...
I20260812 06:17:05.942567 11329 consensus_queue.cc:237] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [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: "b845cf9789484349a078d63f094a230a" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 35013 } }
I20260812 06:17:05.946393 11163 catalog_manager.cc:5719] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a reported cstate change: term changed from 0 to 1, leader changed from <none> to b845cf9789484349a078d63f094a230a (127.10.221.193). New cstate: current_term: 1 leader_uuid: "b845cf9789484349a078d63f094a230a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b845cf9789484349a078d63f094a230a" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 35013 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:06.100225 11127 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.143s	user 0.026s	sys 0.003s
I20260812 06:17:06.119445 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.187753
I20260812 06:17:06.219061 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.099s	user 0.075s	sys 0.024s Metrics: {"bytes_written":4102659,"cfile_init":1,"compiler_manager_pool.queue_time_us":265,"delete_count":0,"dirs.queue_time_us":190,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1465,"drs_written":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4,"lbm_write_time_us":16156,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":155,"peak_mem_usage":0,"reinsert_count":0,"rows_written":100,"thread_start_us":174,"threads_started":1,"update_count":500}
I20260812 06:17:06.220392 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:06.314568 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.094s	user 0.081s	sys 0.012s Metrics: {"cfile_cache_miss":131,"cfile_cache_miss_bytes":8201036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":84,"lbm_read_time_us":4274,"lbm_reads_lt_1ms":163,"lbm_write_time_us":14041,"lbm_writes_lt_1ms":143,"peak_mem_usage":13409612,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":292,"threads_started":5,"update_count":500}
I20260812 06:17:06.315104 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386): 766 bytes on disk
I20260812 06:17:06.315603 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.316177 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=6.157687
I20260812 06:17:06.366555 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.050s	user 0.029s	sys 0.003s Metrics: {"bytes_written":8205081,"delete_count":0,"lbm_write_time_us":15765,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.367260 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:06.387089 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8420,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.387614 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:06.538501 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.151s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16405983,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1020,"lbm_read_time_us":8206,"lbm_reads_lt_1ms":372,"lbm_write_time_us":28213,"lbm_writes_lt_1ms":343,"mutex_wait_us":46,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":1500}
I20260812 06:17:06.539394 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:06.589653 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.050s	user 0.019s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":23214,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:06.590263 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:06.743448 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.153s	user 0.115s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16405860,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":842,"lbm_read_time_us":9468,"lbm_reads_lt_1ms":367,"lbm_write_time_us":32209,"lbm_writes_lt_1ms":343,"mutex_wait_us":63,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":1500}
I20260812 06:17:06.744252 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:06.799877 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.055s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21865,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:06.800468 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:06.816205 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.016s	user 0.004s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.816694 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:06.984923 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.167s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508392,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":9694,"lbm_reads_lt_1ms":464,"lbm_write_time_us":40064,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:06.985669 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:07.036068 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.050s	user 0.045s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23711,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.036680 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.051522 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.052199 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:07.202252 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.150s	user 0.108s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508392,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":323,"lbm_read_time_us":9495,"lbm_reads_lt_1ms":472,"lbm_write_time_us":35318,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:07.203004 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:07.268390 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.065s	user 0.024s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19498,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.269137 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.281718 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.282246 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:07.478891 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.196s	user 0.125s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508391,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2425,"lbm_read_time_us":11466,"lbm_reads_lt_1ms":472,"lbm_write_time_us":39891,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":1656,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:17:07.480219 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:07.527158 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.047s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22587,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.527709 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.543251 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.543809 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:07.697645 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.154s	user 0.133s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508394,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":598,"lbm_read_time_us":8757,"lbm_reads_lt_1ms":468,"lbm_write_time_us":32776,"lbm_writes_lt_1ms":443,"mutex_wait_us":325,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:17:07.699056 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:07.751282 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.051s	user 0.031s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":26049,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.752202 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.775136 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.023s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.775839 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:07.818542 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.042s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152505,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1855,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2239,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:07.819439 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=3.181125
I20260812 06:17:07.836829 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7348,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:07.837364 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling LogGCOp(098a314d975e4ecc88eefd5d6ffc0386): free 112198109 bytes of WAL
I20260812 06:17:07.837680 11245 log_reader.cc:385] T 098a314d975e4ecc88eefd5d6ffc0386: removed 11 log segments from log reader
I20260812 06:17:07.837738 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000001 (ops 1-6)
I20260812 06:17:07.837811 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000002 (ops 7-10)
I20260812 06:17:07.837859 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000003 (ops 11-15)
I20260812 06:17:07.837881 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000004 (ops 16-20)
I20260812 06:17:07.837900 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000005 (ops 21-25)
I20260812 06:17:07.837919 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000006 (ops 26-30)
I20260812 06:17:07.837972 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000007 (ops 31-35)
I20260812 06:17:07.838020 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000008 (ops 36-40)
I20260812 06:17:07.838078 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000009 (ops 41-45)
I20260812 06:17:07.838120 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000010 (ops 46-50)
I20260812 06:17:07.838163 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000011 (ops 51-55)
I20260812 06:17:07.868933 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: LogGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:07.869447 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.887826 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.018s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.888396 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386): 448 bytes on disk
I20260812 06:17:07.888927 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.889520 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:07.907080 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.907829 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:08.149864 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.242s	user 0.193s	sys 0.048s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32815976,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1872,"lbm_read_time_us":15727,"lbm_reads_lt_1ms":775,"lbm_write_time_us":48740,"lbm_writes_lt_1ms":743,"mutex_wait_us":261,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":467,"threads_started":1,"update_count":3500}
I20260812 06:17:08.154990 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:08.267225 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.106s	user 0.061s	sys 0.043s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":37430,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.268786 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=3.181125
I20260812 06:17:08.294099 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.025s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":9271,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:08.294773 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:08.307289 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:08.307865 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:08.573632 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.266s	user 0.179s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28713323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":396,"lbm_read_time_us":17598,"lbm_reads_lt_1ms":673,"lbm_write_time_us":49196,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35968,"update_count":3000}
I20260812 06:17:08.574420 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:08.655048 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.080s	user 0.030s	sys 0.050s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":32688,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.655616 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:08.668555 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.669283 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:08.881177 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.212s	user 0.142s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610805,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":915,"lbm_read_time_us":14226,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40952,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:17:08.881893 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:08.964782 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.083s	user 0.049s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":32126,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.966444 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:08.982851 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.983628 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:09.195808 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.212s	user 0.152s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":17354,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38510,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70656,"update_count":2500}
I20260812 06:17:09.196517 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:09.262838 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.066s	user 0.041s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":32119,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:09.263366 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:09.293375 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.030s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.294016 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:09.319633 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.025s	user 0.005s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5124,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.320447 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:09.546111 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.225s	user 0.122s	sys 0.093s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24610924,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":752,"lbm_read_time_us":14678,"lbm_reads_lt_1ms":573,"lbm_write_time_us":42255,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:09.547405 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:09.606021 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.058s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.606668 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:09.619793 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.620437 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:09.653064 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.032s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1886,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1787,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:09.654052 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386): 448 bytes on disk
I20260812 06:17:09.654620 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:17:09.655180 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:09.673264 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.673926 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling LogGCOp(098a314d975e4ecc88eefd5d6ffc0386): free 120553431 bytes of WAL
I20260812 06:17:09.674196 11245 log_reader.cc:385] T 098a314d975e4ecc88eefd5d6ffc0386: removed 12 log segments from log reader
I20260812 06:17:09.674275 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000012 (ops 56-60)
I20260812 06:17:09.674340 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000013 (ops 61-64)
I20260812 06:17:09.674371 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000014 (ops 65-69)
I20260812 06:17:09.674405 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000015 (ops 70-74)
I20260812 06:17:09.674430 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000016 (ops 75-79)
I20260812 06:17:09.674453 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000017 (ops 80-84)
I20260812 06:17:09.674474 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000018 (ops 85-88)
I20260812 06:17:09.674502 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000019 (ops 89-93)
I20260812 06:17:09.674525 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000020 (ops 94-98)
I20260812 06:17:09.674551 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000021 (ops 99-103)
I20260812 06:17:09.674618 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000022 (ops 104-108)
I20260812 06:17:09.674652 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000023 (ops 109-113)
I20260812 06:17:09.712425 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: LogGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.038s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:09.713274 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:09.938402 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.225s	user 0.159s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28713334,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":333,"lbm_read_time_us":17764,"lbm_reads_lt_1ms":665,"lbm_write_time_us":36959,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33664,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:17:09.940645 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=15.087375
I20260812 06:17:10.016613 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.076s	user 0.040s	sys 0.031s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":26558,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:10.017350 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=4.173312
I20260812 06:17:10.034092 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":5579533,"delete_count":0,"lbm_write_time_us":6883,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:17:10.034914 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.196750
I20260812 06:17:10.043286 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2215504,"delete_count":0,"lbm_write_time_us":2742,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:17:10.043859 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:10.271400 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.227s	user 0.160s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28713289,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":346,"lbm_read_time_us":15982,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40149,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:10.272403 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:10.321045 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.048s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.321954 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:10.479341 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.157s	user 0.125s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20508272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":959,"lbm_read_time_us":11159,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25755,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:17:10.480073 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:10.522765 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.042s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18873,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.523628 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:10.555760 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.032s	user 0.004s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.556317 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:10.567791 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.568321 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:10.786772 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.218s	user 0.130s	sys 0.088s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24610923,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":527,"lbm_read_time_us":15229,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38222,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:10.787614 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:10.839924 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23982,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.840665 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:10.858300 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8393,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.858863 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:11.045693 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.187s	user 0.142s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508392,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":13231,"lbm_reads_lt_1ms":472,"lbm_write_time_us":44535,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:17:11.047617 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:11.102154 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.053s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26228,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.102852 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:11.138839 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.036s	user 0.016s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":9397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.139631 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:11.163174 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.023s	user 0.022s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":9721,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.164193 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:11.350819 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.186s	user 0.169s	sys 0.016s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24610921,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1394,"lbm_read_time_us":12578,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37104,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:11.352510 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=10.126437
I20260812 06:17:11.403440 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.051s	user 0.041s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23394,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.404155 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:11.421245 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.421803 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:11.454485 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushMRSOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":158,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":2246,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2100,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:11.455399 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling LogGCOp(098a314d975e4ecc88eefd5d6ffc0386): free 120553577 bytes of WAL
I20260812 06:17:11.455632 11245 log_reader.cc:385] T 098a314d975e4ecc88eefd5d6ffc0386: removed 12 log segments from log reader
I20260812 06:17:11.455686 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000024 (ops 114-118)
I20260812 06:17:11.455739 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000025 (ops 119-122)
I20260812 06:17:11.455790 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000026 (ops 123-127)
I20260812 06:17:11.455814 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000027 (ops 128-132)
I20260812 06:17:11.455852 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000028 (ops 133-137)
I20260812 06:17:11.455891 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000029 (ops 138-142)
I20260812 06:17:11.455928 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000030 (ops 143-147)
I20260812 06:17:11.455968 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000031 (ops 148-152)
I20260812 06:17:11.456007 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000032 (ops 153-156)
I20260812 06:17:11.456045 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000033 (ops 157-161)
I20260812 06:17:11.456089 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000034 (ops 162-166)
I20260812 06:17:11.456153 11245 log.cc:1079] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/098a314d975e4ecc88eefd5d6ffc0386/wal-000000035 (ops 167-171)
I20260812 06:17:11.488492 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: LogGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.033s	user 0.004s	sys 0.027s Metrics: {}
I20260812 06:17:11.489086 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386): 462 bytes on disk
I20260812 06:17:11.489575 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: UndoDeltaBlockGCOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.490137 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=3.181125
I20260812 06:17:11.511035 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.021s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7802,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:11.511579 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:11.523872 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.524547 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:11.722891 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.198s	user 0.158s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28713444,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1407,"lbm_read_time_us":14994,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40320,"lbm_writes_lt_1ms":643,"mutex_wait_us":86,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:17:11.723832 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:11.787352 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.063s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27442,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.787966 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=2.188937
I20260812 06:17:11.803224 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.803743 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:12.023876 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.220s	user 0.155s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610804,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":349,"lbm_read_time_us":10809,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40339,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:12.024950 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=12.110812
I20260812 06:17:12.069540 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":13538209,"delete_count":0,"lbm_write_time_us":19544,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:17:12.070128 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.196750
I20260812 06:17:12.098134 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.028s	user 0.008s	sys 0.008s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":6569,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:12.098798 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=1.000000
I20260812 06:17:12.318615 11127 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.218s	user 2.252s	sys 0.176s
I20260812 06:17:12.323102 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: MajorDeltaCompactionOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.224s	user 0.156s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508357,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":864,"lbm_read_time_us":23874,"lbm_reads_1-10_ms":3,"lbm_reads_lt_1ms":461,"lbm_write_time_us":40390,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":307,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:12.323921 11315 maintenance_manager.cc:419] P b845cf9789484349a078d63f094a230a: Scheduling FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386): perf score=14.095187
I20260812 06:17:12.386397 11127 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.003s	sys 0.000s
I20260812 06:17:12.387403 11127 tablet_server.cc:179] TabletServer@127.10.221.193:0 shutting down...
I20260812 06:17:12.401216 11245 maintenance_manager.cc:643] P b845cf9789484349a078d63f094a230a: FlushDeltaMemStoresOp(098a314d975e4ecc88eefd5d6ffc0386) complete. Timing: real 0.077s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":46048,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.402081 11127 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:12.402697 11127 tablet_replica.cc:333] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a: stopping tablet replica
I20260812 06:17:12.402921 11127 raft_consensus.cc:2243] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:12.403182 11127 raft_consensus.cc:2272] T 098a314d975e4ecc88eefd5d6ffc0386 P b845cf9789484349a078d63f094a230a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:12.420481 11127 tablet_server.cc:196] TabletServer@127.10.221.193:0 shutdown complete.
I20260812 06:17:12.427521 11127 master.cc:562] Master@127.10.221.254:42959 shutting down...
I20260812 06:17:12.434033 11127 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:12.434295 11127 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:12.434399 11127 tablet_replica.cc:333] T 00000000000000000000000000000000 P bcbfe2fbd0b841f88b7fd6cff8918f4b: stopping tablet replica
I20260812 06:17:12.448732 11127 master.cc:584] Master@127.10.221.254:42959 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6895 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:12.581516 11127 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.221.254:39661
I20260812 06:17:12.582316 11127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:12.586910 11351 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:17:12.586849 11127 server_base.cc:1061] running on GCE node
W20260812 06:17:12.586815 11350 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:17:12.586865 11356 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:17:12.587426 11127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:12.587482 11127 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:17:12.587498 11127 hybrid_clock.cc:648] HybridClock initialized: now 1786515432587498 us; error 0 us; skew 500 ppm
I20260812 06:17:12.588784 11127 webserver.cc:533] Webserver started at http://127.10.221.254:40865/ using document root <none> and password file <none>
I20260812 06:17:12.589022 11127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:12.589092 11127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:12.589156 11127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:12.589615 11127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/master-0-root/instance:
uuid: "7bbb826e3f844d958f7f7b7bbd48907b"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-dhph"
I20260812 06:17:12.592378 11127 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:12.593761 11362 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:17:12.594159 11127 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:12.594254 11127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/master-0-root
uuid: "7bbb826e3f844d958f7f7b7bbd48907b"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-dhph"
I20260812 06:17:12.594321 11127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-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:17:12.614898 11127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.615355 11127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.621531 11127 rpc_server.cc:307] RPC server started. Bound to: 127.10.221.254:39661
I20260812 06:17:12.626441 11422 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.221.254:39661 every 8 connection(s)
I20260812 06:17:12.628203 11423 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:17:12.630363 11423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b: Bootstrap starting.
I20260812 06:17:12.631363 11423 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.632756 11423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b: No bootstrap required, opened a new log
I20260812 06:17:12.633492 11423 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER }
I20260812 06:17:12.633613 11423 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.633656 11423 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7bbb826e3f844d958f7f7b7bbd48907b, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.633849 11423 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [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: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER }
I20260812 06:17:12.633939 11423 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.634011 11423 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.634084 11423 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.635115 11423 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER }
I20260812 06:17:12.635308 11423 leader_election.cc:304] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [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: 7bbb826e3f844d958f7f7b7bbd48907b; no voters: 
I20260812 06:17:12.635608 11423 leader_election.cc:290] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.635890 11429 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.636150 11429 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 1 LEADER]: Becoming Leader. State: Replica: 7bbb826e3f844d958f7f7b7bbd48907b, State: Running, Role: LEADER
I20260812 06:17:12.636330 11423 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:12.636343 11429 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [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: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER }
I20260812 06:17:12.636993 11431 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7bbb826e3f844d958f7f7b7bbd48907b. Latest consensus state: current_term: 1 leader_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER } }
I20260812 06:17:12.637156 11431 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.637277 11430 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7bbb826e3f844d958f7f7b7bbd48907b" member_type: VOTER } }
I20260812 06:17:12.637406 11430 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.637936 11435 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:12.638880 11435 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:12.639479 11127 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:12.641887 11435 catalog_manager.cc:1383] Generated new cluster ID: 2b16394a56904e1d85e11742dab171db
I20260812 06:17:12.642131 11435 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:12.688388 11435 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:12.689142 11435 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:12.702013 11435 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b: Generated new TSK 0
I20260812 06:17:12.702322 11435 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:12.704854 11127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:12.708668 11451 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:17:12.708751 11449 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:17:12.708786 11447 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:17:12.708732 11127 server_base.cc:1061] running on GCE node
I20260812 06:17:12.709120 11127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:12.709215 11127 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:17:12.709246 11127 hybrid_clock.cc:648] HybridClock initialized: now 1786515432709246 us; error 0 us; skew 500 ppm
I20260812 06:17:12.711449 11127 webserver.cc:533] Webserver started at http://127.10.221.193:41423/ using document root <none> and password file <none>
I20260812 06:17:12.711711 11127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:12.711828 11127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:12.711894 11127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:12.712666 11127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/instance:
uuid: "31cf71967dec487db08b8c7000f13c51"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-dhph"
I20260812 06:17:12.714972 11127 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:12.716948 11456 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:17:12.717613 11127 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:12.717713 11127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root
uuid: "31cf71967dec487db08b8c7000f13c51"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-dhph"
I20260812 06:17:12.717795 11127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-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:17:12.739804 11127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.740350 11127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.740722 11127 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:12.741389 11127 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:12.741432 11127 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.741470 11127 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:12.741487 11127 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.748500 11127 rpc_server.cc:307] RPC server started. Bound to: 127.10.221.193:44307
I20260812 06:17:12.749389 11527 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.221.193:44307 every 8 connection(s)
I20260812 06:17:12.765339 11528 heartbeater.cc:344] Connected to a master server at 127.10.221.254:39661
I20260812 06:17:12.765494 11528 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:12.765761 11528 heartbeater.cc:507] Master 127.10.221.254:39661 requested a full tablet report, sending...
I20260812 06:17:12.766917 11382 ts_manager.cc:194] Registered new tserver with Master: 31cf71967dec487db08b8c7000f13c51 (127.10.221.193:44307)
I20260812 06:17:12.767346 11127 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01782786s
I20260812 06:17:12.767889 11382 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32794
I20260812 06:17:12.778218 11382 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32810:
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:17:12.792093 11488 tablet_service.cc:1511] Processing CreateTablet for tablet 77ec4cbbef544000ae321cc795a488fe (DEFAULT_TABLE table=heavy-update-compaction-test [id=8e761c4909884a48b2a486146f526e1d]), partition=
I20260812 06:17:12.792470 11488 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 77ec4cbbef544000ae321cc795a488fe. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:12.795680 11542 tablet_bootstrap.cc:492] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Bootstrap starting.
I20260812 06:17:12.796777 11542 tablet_bootstrap.cc:654] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.798660 11542 tablet_bootstrap.cc:492] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: No bootstrap required, opened a new log
I20260812 06:17:12.798785 11542 ts_tablet_manager.cc:1403] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:12.799505 11542 raft_consensus.cc:359] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31cf71967dec487db08b8c7000f13c51" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 44307 } }
I20260812 06:17:12.799788 11542 raft_consensus.cc:385] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.799885 11542 raft_consensus.cc:740] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 31cf71967dec487db08b8c7000f13c51, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.800022 11542 consensus_queue.cc:260] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [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: "31cf71967dec487db08b8c7000f13c51" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 44307 } }
I20260812 06:17:12.800125 11542 raft_consensus.cc:399] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.800189 11542 raft_consensus.cc:493] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.800243 11542 raft_consensus.cc:3060] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.801268 11542 raft_consensus.cc:515] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31cf71967dec487db08b8c7000f13c51" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 44307 } }
I20260812 06:17:12.801465 11542 leader_election.cc:304] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [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: 31cf71967dec487db08b8c7000f13c51; no voters: 
I20260812 06:17:12.802457 11542 leader_election.cc:290] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.802484 11544 raft_consensus.cc:2804] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.803242 11544 raft_consensus.cc:697] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 1 LEADER]: Becoming Leader. State: Replica: 31cf71967dec487db08b8c7000f13c51, State: Running, Role: LEADER
I20260812 06:17:12.803453 11544 consensus_queue.cc:237] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [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: "31cf71967dec487db08b8c7000f13c51" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 44307 } }
I20260812 06:17:12.803457 11528 heartbeater.cc:499] Master 127.10.221.254:39661 was elected leader, sending a full tablet report...
I20260812 06:17:12.803642 11542 ts_tablet_manager.cc:1434] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Time spent starting tablet: real 0.005s	user 0.005s	sys 0.000s
I20260812 06:17:12.805655 11382 catalog_manager.cc:5719] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 reported cstate change: term changed from 0 to 1, leader changed from <none> to 31cf71967dec487db08b8c7000f13c51 (127.10.221.193). New cstate: current_term: 1 leader_uuid: "31cf71967dec487db08b8c7000f13c51" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31cf71967dec487db08b8c7000f13c51" member_type: VOTER last_known_addr { host: "127.10.221.193" port: 44307 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:12.887666 11127 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.070s	user 0.017s	sys 0.012s
I20260812 06:17:13.000485 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushMRSOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.125253
I20260812 06:17:13.155146 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushMRSOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.154s	user 0.129s	sys 0.024s Metrics: {"bytes_written":8984541,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":343,"dirs.run_wall_time_us":1290,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34754,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":474,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":896,"update_count":1095}
I20260812 06:17:13.156412 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling LogGCOp(77ec4cbbef544000ae321cc795a488fe): free 8725963 bytes of WAL
I20260812 06:17:13.156705 11463 log_reader.cc:385] T 77ec4cbbef544000ae321cc795a488fe: removed 1 log segments from log reader
I20260812 06:17:13.156762 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000001 (ops 1-6)
I20260812 06:17:13.160740 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: LogGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:13.161701 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:13.199769 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.038s	user 0.012s	sys 0.006s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":6684,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:17:13.200397 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:13.213712 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.214466 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:13.386533 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.172s	user 0.102s	sys 0.069s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20590450,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":615,"lbm_read_time_us":14157,"lbm_reads_lt_1ms":473,"lbm_write_time_us":30972,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":331,"threads_started":5,"update_count":2000}
I20260812 06:17:13.387110 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe): 8206537 bytes on disk
I20260812 06:17:13.388080 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.388624 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:13.438673 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.048s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17060,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.439262 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:13.452622 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.453123 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:13.614142 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.161s	user 0.140s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2263,"lbm_read_time_us":8268,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31936,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.615084 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:13.659662 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.044s	user 0.035s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18614,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.660215 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:13.673451 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.674052 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:13.842507 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.168s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1278,"lbm_read_time_us":11293,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":32966,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:17:13.843478 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:13.906543 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.063s	user 0.035s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":22506,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.907303 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:13.923099 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.923861 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:14.129081 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.205s	user 0.136s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":14826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32498,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:17:14.130868 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:14.197408 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.065s	user 0.031s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":27684,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.198652 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:14.217258 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.218271 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:14.385183 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.167s	user 0.114s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":11788,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33944,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:14.386713 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:14.434965 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.048s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12348515,"delete_count":0,"lbm_write_time_us":20630,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1505}
I20260812 06:17:14.435596 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:14.452726 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":6659,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:14.453244 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:14.607069 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.154s	user 0.111s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":778,"lbm_read_time_us":11553,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28149,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:17:14.607992 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:14.666028 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.058s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.667320 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:14.685824 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.686410 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushMRSOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:14.746841 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushMRSOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.060s	user 0.041s	sys 0.001s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":2448,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2033,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:14.747701 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling LogGCOp(77ec4cbbef544000ae321cc795a488fe): free 115490132 bytes of WAL
I20260812 06:17:14.747994 11463 log_reader.cc:385] T 77ec4cbbef544000ae321cc795a488fe: removed 11 log segments from log reader
I20260812 06:17:14.748056 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000002 (ops 7-11)
I20260812 06:17:14.748109 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000003 (ops 12-16)
I20260812 06:17:14.748157 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000004 (ops 17-21)
I20260812 06:17:14.748229 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000005 (ops 22-26)
I20260812 06:17:14.748275 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000006 (ops 27-31)
I20260812 06:17:14.748307 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000007 (ops 32-36)
I20260812 06:17:14.748327 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000008 (ops 37-41)
I20260812 06:17:14.748369 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000009 (ops 42-46)
I20260812 06:17:14.748409 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000010 (ops 47-50)
I20260812 06:17:14.748456 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000011 (ops 51-55)
I20260812 06:17:14.748503 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000012 (ops 56-60)
I20260812 06:17:14.780882 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: LogGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:14.781466 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:14.800395 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4143685,"delete_count":0,"lbm_write_time_us":5578,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:14.801023 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe): 447 bytes on disk
I20260812 06:17:14.801488 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:14.801983 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:14.818024 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":5619,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:14.818670 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:15.108397 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.289s	user 0.216s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795411,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":766,"lbm_read_time_us":20088,"lbm_reads_lt_1ms":674,"lbm_write_time_us":47993,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":641,"mutex_wait_us":603,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:17:15.109917 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:15.203421 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.093s	user 0.065s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":45324,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.204725 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:15.248157 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.043s	user 0.026s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.249280 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:15.266553 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.267400 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:15.539404 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.272s	user 0.157s	sys 0.114s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795290,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1012,"lbm_read_time_us":17921,"lbm_reads_lt_1ms":673,"lbm_write_time_us":42900,"lbm_writes_lt_1ms":643,"mutex_wait_us":482,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:17:15.540263 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=15.087375
I20260812 06:17:15.612432 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.072s	user 0.053s	sys 0.017s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":33207,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:15.614441 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:15.634527 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":8180,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.635421 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:15.850955 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.215s	user 0.166s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":12983,"lbm_reads_lt_1ms":568,"lbm_write_time_us":37510,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":123,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:15.851948 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:15.921065 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.069s	user 0.044s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.921808 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:15.936708 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.937387 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:16.172324 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.235s	user 0.164s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":876,"lbm_read_time_us":18210,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35734,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:17:16.173251 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:16.273110 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.100s	user 0.037s	sys 0.058s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":39072,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.274127 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:16.287861 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.288448 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:16.521741 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.233s	user 0.140s	sys 0.087s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1055,"lbm_read_time_us":17498,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37372,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":185984,"update_count":2500}
I20260812 06:17:16.522465 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=11.118625
I20260812 06:17:16.565721 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.043s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17350,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:16.566828 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:16.588476 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.021s	user 0.015s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":8981,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.589222 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:16.793059 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.204s	user 0.148s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590339,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":896,"lbm_read_time_us":11321,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28605,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":35328,"update_count":2000}
I20260812 06:17:16.793754 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=10.126437
I20260812 06:17:16.854107 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.060s	user 0.031s	sys 0.025s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":26698,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.857250 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:16.881831 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.024s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.882822 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:16.897959 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6097,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.898622 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushMRSOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:16.954957 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushMRSOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.056s	user 0.055s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":233,"dirs.run_cpu_time_us":640,"dirs.run_wall_time_us":4022,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2619,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:16.956447 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling LogGCOp(77ec4cbbef544000ae321cc795a488fe): free 129320502 bytes of WAL
I20260812 06:17:16.956771 11463 log_reader.cc:385] T 77ec4cbbef544000ae321cc795a488fe: removed 13 log segments from log reader
I20260812 06:17:16.956838 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000013 (ops 61-65)
I20260812 06:17:16.956897 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000014 (ops 66-70)
I20260812 06:17:16.956959 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000015 (ops 71-75)
I20260812 06:17:16.957008 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000016 (ops 76-80)
I20260812 06:17:16.957049 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000017 (ops 81-85)
I20260812 06:17:16.957093 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000018 (ops 86-90)
I20260812 06:17:16.957137 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000019 (ops 91-94)
I20260812 06:17:16.957181 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000020 (ops 95-99)
I20260812 06:17:16.957226 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000021 (ops 100-104)
I20260812 06:17:16.957274 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000022 (ops 105-108)
I20260812 06:17:16.957319 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000023 (ops 109-113)
I20260812 06:17:16.957358 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000024 (ops 114-118)
I20260812 06:17:16.957397 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000025 (ops 119-123)
I20260812 06:17:17.003445 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: LogGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.047s	user 0.000s	sys 0.046s Metrics: {}
I20260812 06:17:17.003959 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe): 493 bytes on disk
I20260812 06:17:17.004462 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:17.005039 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=3.181125
I20260812 06:17:17.025133 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8694,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":550}
I20260812 06:17:17.026109 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:17.061100 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.034s	user 0.014s	sys 0.018s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6130,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.061941 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:17.396135 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.334s	user 0.196s	sys 0.132s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32897930,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":413,"lbm_read_time_us":21487,"lbm_reads_lt_1ms":767,"lbm_write_time_us":58901,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":741,"mutex_wait_us":70,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1071232,"thread_start_us":437,"threads_started":6,"update_count":3500}
I20260812 06:17:17.396860 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=18.063937
I20260812 06:17:17.491897 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.095s	user 0.058s	sys 0.025s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":37082,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"mutex_wait_us":25,"reinsert_count":0,"update_count":2500}
I20260812 06:17:17.492643 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:17.508878 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.510277 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:17.787983 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.277s	user 0.196s	sys 0.081s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795170,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":740,"lbm_read_time_us":17759,"lbm_reads_lt_1ms":672,"lbm_write_time_us":47991,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":259456,"update_count":3000}
I20260812 06:17:17.788853 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:17.861222 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.071s	user 0.053s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30851,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.861986 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:17.883019 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.021s	user 0.020s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.883570 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:18.131340 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.248s	user 0.167s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1672,"lbm_read_time_us":17695,"lbm_reads_lt_1ms":564,"lbm_write_time_us":42834,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:18.132359 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:18.230954 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.098s	user 0.067s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":42337,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.232086 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:18.248785 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.249511 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:18.455808 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.206s	user 0.154s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":16216,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35486,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":130816,"update_count":2500}
I20260812 06:17:18.456723 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=14.095187
I20260812 06:17:18.533664 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.077s	user 0.038s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29767,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.534734 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:18.547817 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.548790 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:18.762825 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.213s	user 0.157s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":732,"lbm_read_time_us":16246,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35234,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2500}
I20260812 06:17:18.763999 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=11.118625
I20260812 06:17:18.835891 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.072s	user 0.038s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":29558,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:18.836705 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=6.157687
I20260812 06:17:18.872632 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.036s	user 0.011s	sys 0.023s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11205,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:18.873694 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushMRSOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:18.939209 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushMRSOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.065s	user 0.043s	sys 0.005s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":329,"dirs.run_cpu_time_us":455,"dirs.run_wall_time_us":2549,"drs_written":1,"lbm_read_time_us":578,"lbm_reads_lt_1ms":4,"lbm_write_time_us":4096,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:18.939975 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe): 462 bytes on disk
I20260812 06:17:18.940436 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: UndoDeltaBlockGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.941033 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=3.181125
I20260812 06:17:18.962107 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.021s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":10543,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":550}
I20260812 06:17:18.962723 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling LogGCOp(77ec4cbbef544000ae321cc795a488fe): free 121006675 bytes of WAL
I20260812 06:17:18.963012 11463 log_reader.cc:385] T 77ec4cbbef544000ae321cc795a488fe: removed 12 log segments from log reader
I20260812 06:17:18.963057 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000026 (ops 124-128)
I20260812 06:17:18.963088 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000027 (ops 129-133)
I20260812 06:17:18.963152 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000028 (ops 134-138)
I20260812 06:17:18.963200 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000029 (ops 139-142)
I20260812 06:17:18.963259 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000030 (ops 143-147)
I20260812 06:17:18.963290 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000031 (ops 148-152)
I20260812 06:17:18.963307 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000032 (ops 153-157)
I20260812 06:17:18.963331 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000033 (ops 158-162)
I20260812 06:17:18.963387 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000034 (ops 163-167)
I20260812 06:17:18.963428 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000035 (ops 168-172)
I20260812 06:17:18.963469 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000036 (ops 173-177)
I20260812 06:17:18.963507 11463 log.cc:1079] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: Deleting log segment in path: /tmp/dist-test-taskNSYo8d/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425659017-11127-0/minicluster-data/ts-0-root/wals/77ec4cbbef544000ae321cc795a488fe/wal-000000037 (ops 178-182)
I20260812 06:17:18.995363 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: LogGCOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.032s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:18.996600 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:19.025071 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.028s	user 0.018s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7913,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.025925 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:19.042455 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6608,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.043476 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:19.344496 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.301s	user 0.221s	sys 0.079s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37000347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":783,"lbm_read_time_us":20101,"lbm_reads_lt_1ms":875,"lbm_write_time_us":53434,"lbm_writes_lt_1ms":843,"mutex_wait_us":27,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":17152,"thread_start_us":408,"threads_started":6,"update_count":4000}
I20260812 06:17:19.346207 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=18.063937
I20260812 06:17:19.424212 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.077s	user 0.044s	sys 0.032s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":34368,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.424965 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe): perf score=2.188937
I20260812 06:17:19.447273 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: FlushDeltaMemStoresOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.022s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.448489 11529 maintenance_manager.cc:419] P 31cf71967dec487db08b8c7000f13c51: Scheduling MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe): perf score=1.000000
I20260812 06:17:19.464802 11127 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.577s	user 2.308s	sys 0.236s
I20260812 06:17:19.541431 11127 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:17:19.542007 11127 tablet_server.cc:179] TabletServer@127.10.221.193:0 shutting down...
I20260812 06:17:19.646051 11463 maintenance_manager.cc:643] P 31cf71967dec487db08b8c7000f13c51: MajorDeltaCompactionOp(77ec4cbbef544000ae321cc795a488fe) complete. Timing: real 0.197s	user 0.153s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795174,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":16655,"lbm_reads_lt_1ms":660,"lbm_write_time_us":36518,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":291968,"update_count":3000}
I20260812 06:17:19.646788 11127 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:19.647197 11127 tablet_replica.cc:333] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51: stopping tablet replica
I20260812 06:17:19.647493 11127 raft_consensus.cc:2243] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:19.647727 11127 raft_consensus.cc:2272] T 77ec4cbbef544000ae321cc795a488fe P 31cf71967dec487db08b8c7000f13c51 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:19.656162 11127 tablet_server.cc:196] TabletServer@127.10.221.193:0 shutdown complete.
I20260812 06:17:19.700770 11127 master.cc:562] Master@127.10.221.254:39661 shutting down...
I20260812 06:17:19.704784 11127 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:19.705089 11127 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:19.705183 11127 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7bbb826e3f844d958f7f7b7bbd48907b: stopping tablet replica
I20260812 06:17:19.718639 11127 master.cc:584] Master@127.10.221.254:39661 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7272 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (14169 ms total)

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