[==========] 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:26.623479  5352 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.58.62:45459
I20260812 06:17:26.624558  5352 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:26.625160  5352 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.631726  5361 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:26.631783  5352 server_base.cc:1061] running on GCE node
W20260812 06:17:26.631735  5367 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:26.632030  5364 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:26.632553  5352 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.632651  5352 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:26.632682  5352 hybrid_clock.cc:648] HybridClock initialized: now 1786515446632681 us; error 0 us; skew 500 ppm
I20260812 06:17:26.634379  5352 webserver.cc:533] Webserver started at http://127.5.58.62:34671/ using document root <none> and password file <none>
I20260812 06:17:26.634891  5352 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.634943  5352 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.635147  5352 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.636813  5352 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/master-0-root/instance:
uuid: "1b89c152f33840beba94450bb9fa7a5b"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-pww0"
I20260812 06:17:26.640347  5352 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:26.642473  5381 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:26.643535  5352 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:26.643651  5352 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/master-0-root
uuid: "1b89c152f33840beba94450bb9fa7a5b"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-pww0"
I20260812 06:17:26.643744  5352 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-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:26.671247  5352 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.672004  5352 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:26.672194  5352 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.679945  5478 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.58.62:45459 every 8 connection(s)
I20260812 06:17:26.679942  5352 rpc_server.cc:307] RPC server started. Bound to: 127.5.58.62:45459
I20260812 06:17:26.682212  5479 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:26.687745  5479 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: Bootstrap starting.
I20260812 06:17:26.690038  5479 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.690953  5479 log.cc:826] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:26.692708  5479 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: No bootstrap required, opened a new log
I20260812 06:17:26.695482  5479 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER }
I20260812 06:17:26.695679  5479 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.695740  5479 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1b89c152f33840beba94450bb9fa7a5b, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.696298  5479 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [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: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER }
I20260812 06:17:26.696431  5479 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.696476  5479 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.696563  5479 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.697458  5479 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER }
I20260812 06:17:26.697978  5479 leader_election.cc:304] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [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: 1b89c152f33840beba94450bb9fa7a5b; no voters: 
I20260812 06:17:26.698307  5479 leader_election.cc:290] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.698469  5488 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.698714  5488 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 1 LEADER]: Becoming Leader. State: Replica: 1b89c152f33840beba94450bb9fa7a5b, State: Running, Role: LEADER
I20260812 06:17:26.699090  5488 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [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: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER }
I20260812 06:17:26.699326  5479 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:26.700965  5489 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1b89c152f33840beba94450bb9fa7a5b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER } }
I20260812 06:17:26.701051  5492 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1b89c152f33840beba94450bb9fa7a5b. Latest consensus state: current_term: 1 leader_uuid: "1b89c152f33840beba94450bb9fa7a5b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b89c152f33840beba94450bb9fa7a5b" member_type: VOTER } }
I20260812 06:17:26.701098  5489 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.701143  5492 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.701498  5508 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:26.703814  5508 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:26.704149  5352 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:26.708278  5508 catalog_manager.cc:1383] Generated new cluster ID: 94e187fe2e414a9ab1d1d3a6929990d8
I20260812 06:17:26.708348  5508 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:26.723702  5508 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:26.724893  5508 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:26.733596  5508 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: Generated new TSK 0
I20260812 06:17:26.734368  5508 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:26.736753  5352 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.739763  5528 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:26.739825  5352 server_base.cc:1061] running on GCE node
W20260812 06:17:26.739696  5525 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:26.739725  5531 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:26.740150  5352 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.740193  5352 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:26.740207  5352 hybrid_clock.cc:648] HybridClock initialized: now 1786515446740208 us; error 0 us; skew 500 ppm
I20260812 06:17:26.741081  5352 webserver.cc:533] Webserver started at http://127.5.58.1:36929/ using document root <none> and password file <none>
I20260812 06:17:26.741245  5352 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.741303  5352 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.741379  5352 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.741744  5352 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/instance:
uuid: "93c46c21c6a847038978fb82afda5bd4"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-pww0"
I20260812 06:17:26.743198  5352 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:26.744197  5536 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:26.744467  5352 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:26.744539  5352 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root
uuid: "93c46c21c6a847038978fb82afda5bd4"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-pww0"
I20260812 06:17:26.744613  5352 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-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:26.761003  5352 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.761474  5352 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.761973  5352 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:26.762831  5352 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:26.762883  5352 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.762928  5352 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:26.762956  5352 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.769245  5352 rpc_server.cc:307] RPC server started. Bound to: 127.5.58.1:40643
I20260812 06:17:26.769277  5645 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.58.1:40643 every 8 connection(s)
I20260812 06:17:26.782130  5648 heartbeater.cc:344] Connected to a master server at 127.5.58.62:45459
I20260812 06:17:26.782394  5648 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:26.782868  5648 heartbeater.cc:507] Master 127.5.58.62:45459 requested a full tablet report, sending...
I20260812 06:17:26.784312  5414 ts_manager.cc:194] Registered new tserver with Master: 93c46c21c6a847038978fb82afda5bd4 (127.5.58.1:40643)
I20260812 06:17:26.784379  5352 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014519518s
I20260812 06:17:26.785846  5414 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33772
I20260812 06:17:26.793941  5414 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33778:
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:26.807643  5589 tablet_service.cc:1511] Processing CreateTablet for tablet 7a76ab6421164ea59dd77f02f7816ade (DEFAULT_TABLE table=heavy-update-compaction-test [id=b665231750454b589a775269eb856ef8]), partition=
I20260812 06:17:26.808120  5589 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7a76ab6421164ea59dd77f02f7816ade. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:26.810297  5671 tablet_bootstrap.cc:492] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Bootstrap starting.
I20260812 06:17:26.811259  5671 tablet_bootstrap.cc:654] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.812431  5671 tablet_bootstrap.cc:492] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: No bootstrap required, opened a new log
I20260812 06:17:26.812533  5671 ts_tablet_manager.cc:1403] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:26.812966  5671 raft_consensus.cc:359] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93c46c21c6a847038978fb82afda5bd4" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 40643 } }
I20260812 06:17:26.813072  5671 raft_consensus.cc:385] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.813104  5671 raft_consensus.cc:740] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 93c46c21c6a847038978fb82afda5bd4, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.813244  5671 consensus_queue.cc:260] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [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: "93c46c21c6a847038978fb82afda5bd4" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 40643 } }
I20260812 06:17:26.813333  5671 raft_consensus.cc:399] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.813378  5671 raft_consensus.cc:493] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.813422  5671 raft_consensus.cc:3060] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.814141  5671 raft_consensus.cc:515] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93c46c21c6a847038978fb82afda5bd4" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 40643 } }
I20260812 06:17:26.814271  5671 leader_election.cc:304] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [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: 93c46c21c6a847038978fb82afda5bd4; no voters: 
I20260812 06:17:26.814529  5671 leader_election.cc:290] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.814651  5678 raft_consensus.cc:2804] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.814853  5671 ts_tablet_manager.cc:1434] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:26.815035  5678 raft_consensus.cc:697] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 1 LEADER]: Becoming Leader. State: Replica: 93c46c21c6a847038978fb82afda5bd4, State: Running, Role: LEADER
I20260812 06:17:26.815219  5678 consensus_queue.cc:237] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [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: "93c46c21c6a847038978fb82afda5bd4" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 40643 } }
I20260812 06:17:26.815655  5648 heartbeater.cc:499] Master 127.5.58.62:45459 was elected leader, sending a full tablet report...
I20260812 06:17:26.817956  5414 catalog_manager.cc:5719] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 93c46c21c6a847038978fb82afda5bd4 (127.5.58.1). New cstate: current_term: 1 leader_uuid: "93c46c21c6a847038978fb82afda5bd4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93c46c21c6a847038978fb82afda5bd4" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 40643 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:26.890862  5352 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.020s	sys 0.012s
I20260812 06:17:27.020354  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade): perf score=15.086190
I20260812 06:17:27.169024  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.148s	user 0.106s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":212,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1004,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33625,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":112,"threads_started":1,"update_count":1450}
I20260812 06:17:27.170214  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling LogGCOp(7a76ab6421164ea59dd77f02f7816ade): free 20743880 bytes of WAL
I20260812 06:17:27.170543  5550 log_reader.cc:385] T 7a76ab6421164ea59dd77f02f7816ade: removed 2 log segments from log reader
I20260812 06:17:27.170619  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000001 (ops 1-6)
I20260812 06:17:27.170670  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000002 (ops 7-11)
I20260812 06:17:27.175249  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: LogGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:27.175706  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:27.192477  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.193009  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:27.315373  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.122s	user 0.090s	sys 0.030s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":540,"lbm_read_time_us":6582,"lbm_reads_lt_1ms":454,"lbm_write_time_us":22964,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":319,"threads_started":5,"update_count":1950}
I20260812 06:17:27.316284  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade): 12719217 bytes on disk
I20260812 06:17:27.316774  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.317273  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:27.356652  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13873,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.357161  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:27.367813  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.368480  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:27.483438  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.115s	user 0.098s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":6991,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21668,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:27.483984  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:27.525591  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.041s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12660,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.526171  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:27.536899  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.537467  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:27.663440  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.126s	user 0.097s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":774,"lbm_read_time_us":7274,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24324,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:27.664031  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:27.714066  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.050s	user 0.035s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15236,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.714715  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:27.732198  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.732731  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:27.873296  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.140s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":9380,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20697,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39552,"update_count":2000}
I20260812 06:17:27.873895  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:27.914742  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.041s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13696,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.915342  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:27.926249  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.926903  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:28.049127  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.122s	user 0.092s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":9085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23105,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:17:28.049655  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:28.090539  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.041s	user 0.026s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14457,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.091110  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:28.103614  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.104101  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:28.227427  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.123s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":883,"lbm_read_time_us":9456,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23174,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":85504,"update_count":2000}
I20260812 06:17:28.227993  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:28.276222  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.048s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14938,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:17:28.276888  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:28.287493  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.287943  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:28.422730  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.135s	user 0.092s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1145,"lbm_read_time_us":10169,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20641,"lbm_writes_lt_1ms":443,"mutex_wait_us":287,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:28.423270  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:28.467517  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.044s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14982,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.468129  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:28.478734  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.479308  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:28.508636  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.029s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1372,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1358,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:28.509438  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling LogGCOp(7a76ab6421164ea59dd77f02f7816ade): free 121006437 bytes of WAL
I20260812 06:17:28.509689  5550 log_reader.cc:385] T 7a76ab6421164ea59dd77f02f7816ade: removed 12 log segments from log reader
I20260812 06:17:28.509761  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000003 (ops 12-16)
I20260812 06:17:28.509805  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000004 (ops 17-21)
I20260812 06:17:28.509838  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000005 (ops 22-26)
I20260812 06:17:28.509871  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000006 (ops 27-31)
I20260812 06:17:28.509902  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000007 (ops 32-36)
I20260812 06:17:28.509930  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000008 (ops 37-41)
I20260812 06:17:28.509958  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000009 (ops 42-46)
I20260812 06:17:28.509990  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000010 (ops 47-51)
I20260812 06:17:28.510021  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000011 (ops 52-56)
I20260812 06:17:28.510049  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000012 (ops 57-60)
I20260812 06:17:28.510077  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000013 (ops 61-65)
I20260812 06:17:28.510115  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000014 (ops 66-70)
I20260812 06:17:28.535811  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: LogGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.026s	user 0.001s	sys 0.024s Metrics: {}
I20260812 06:17:28.536283  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=3.181125
I20260812 06:17:28.557812  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.021s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.558444  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade): 482 bytes on disk
I20260812 06:17:28.558977  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.559544  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:28.569020  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3339,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.569492  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:28.765252  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.196s	user 0.140s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1713,"lbm_read_time_us":12510,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31057,"lbm_writes_lt_1ms":643,"mutex_wait_us":1295,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:17:28.765780  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=14.095187
I20260812 06:17:28.821218  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.055s	user 0.019s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.821969  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:28.837608  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.838169  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.009815  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.171s	user 0.125s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":12935,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29665,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:17:29.010399  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:29.045352  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.035s	user 0.010s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13505,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.045866  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.057859  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.058516  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.183631  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.125s	user 0.095s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1974,"lbm_read_time_us":7177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22793,"lbm_writes_lt_1ms":443,"mutex_wait_us":1553,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38016,"update_count":2000}
I20260812 06:17:29.184218  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:29.228837  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.044s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14942,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.229439  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.240713  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.241348  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.356854  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.115s	user 0.080s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":7706,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20984,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:29.357332  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:29.401540  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.044s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17951,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.402074  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.412473  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.413108  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.530393  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.117s	user 0.091s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":8256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20296,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:17:29.530893  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:29.583247  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.052s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18912,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.583812  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.594887  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.595387  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.737120  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.142s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21178,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:17:29.737762  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:29.777102  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.039s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16533,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.777737  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.792479  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.792969  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:29.818545  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1185,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1632,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:29.819350  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling LogGCOp(7a76ab6421164ea59dd77f02f7816ade): free 115943175 bytes of WAL
I20260812 06:17:29.819653  5550 log_reader.cc:385] T 7a76ab6421164ea59dd77f02f7816ade: removed 11 log segments from log reader
I20260812 06:17:29.819712  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000015 (ops 71-75)
I20260812 06:17:29.819749  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000016 (ops 76-80)
I20260812 06:17:29.819787  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000017 (ops 81-85)
I20260812 06:17:29.819825  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000018 (ops 86-90)
I20260812 06:17:29.819867  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000019 (ops 91-95)
I20260812 06:17:29.819907  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000020 (ops 96-100)
I20260812 06:17:29.819945  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000021 (ops 101-105)
I20260812 06:17:29.819983  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000022 (ops 106-110)
I20260812 06:17:29.820021  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000023 (ops 111-115)
I20260812 06:17:29.820061  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000024 (ops 116-120)
I20260812 06:17:29.820101  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000025 (ops 121-125)
I20260812 06:17:29.843055  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: LogGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:17:29.843693  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=3.181125
I20260812 06:17:29.867764  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.024s	user 0.016s	sys 0.008s Metrics: {"bytes_written":4553932,"delete_count":0,"lbm_write_time_us":7445,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:29.868299  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade): 446 bytes on disk
I20260812 06:17:29.868760  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.869267  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:29.878818  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3382,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:29.879287  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.075796  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.196s	user 0.145s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877332,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":619,"lbm_read_time_us":12758,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33981,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:17:30.076498  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=14.095187
I20260812 06:17:30.137061  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.060s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20547,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.137854  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:30.153158  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.153723  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.321146  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.167s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":12163,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28484,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:30.323045  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=11.118625
I20260812 06:17:30.351677  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.028s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12179,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:30.352250  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:30.363205  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3561,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.363950  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.499531  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.135s	user 0.083s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":336,"lbm_read_time_us":9150,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25075,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:30.500101  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:30.534786  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.035s	user 0.016s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.535421  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.652033  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.116s	user 0.084s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":193,"lbm_read_time_us":7530,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19618,"lbm_writes_lt_1ms":343,"mutex_wait_us":30,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":1500}
I20260812 06:17:30.652667  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:30.683108  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.030s	user 0.012s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13477,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.683712  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.804134  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.120s	user 0.095s	sys 0.025s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":189,"lbm_read_time_us":7510,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19199,"lbm_writes_lt_1ms":343,"mutex_wait_us":47,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":1500}
I20260812 06:17:30.804764  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:30.848174  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.043s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12883,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.848659  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:30.859727  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.860424  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:30.983605  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.123s	user 0.103s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1083,"lbm_read_time_us":9615,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21315,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:30.984180  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:31.026479  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.042s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14299,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.027127  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:31.038503  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.039233  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:31.158959  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.119s	user 0.101s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":7799,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21458,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:31.159721  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:31.209581  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.210338  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:31.224023  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.224534  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:31.252744  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushMRSOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1164,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1364,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:31.253602  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade): 447 bytes on disk
I20260812 06:17:31.254069  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: UndoDeltaBlockGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.254741  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:31.413100  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.158s	user 0.095s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":762,"lbm_read_time_us":8439,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25256,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.413663  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling LogGCOp(7a76ab6421164ea59dd77f02f7816ade): free 124257498 bytes of WAL
I20260812 06:17:31.413873  5550 log_reader.cc:385] T 7a76ab6421164ea59dd77f02f7816ade: removed 12 log segments from log reader
I20260812 06:17:31.413914  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000026 (ops 126-130)
I20260812 06:17:31.413954  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000027 (ops 131-135)
I20260812 06:17:31.413987  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000028 (ops 136-140)
I20260812 06:17:31.414019  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000029 (ops 141-144)
I20260812 06:17:31.414050  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000030 (ops 145-149)
I20260812 06:17:31.414081  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000031 (ops 150-154)
I20260812 06:17:31.414111  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000032 (ops 155-159)
I20260812 06:17:31.414148  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000033 (ops 160-164)
I20260812 06:17:31.414180  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000034 (ops 165-169)
I20260812 06:17:31.414211  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000035 (ops 170-174)
I20260812 06:17:31.414242  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000036 (ops 175-179)
I20260812 06:17:31.414273  5550 log.cc:1079] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a76ab6421164ea59dd77f02f7816ade/wal-000000037 (ops 180-184)
I20260812 06:17:31.438898  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: LogGCOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:31.439586  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=15.087375
I20260812 06:17:31.482625  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.043s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":17720,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:31.483229  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:31.503090  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.020s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.503830  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=2.188937
I20260812 06:17:31.517282  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5153,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.517863  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:31.668661  5352 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.778s	user 1.673s	sys 0.183s
I20260812 06:17:31.699421  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.181s	user 0.124s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":13040,"lbm_reads_lt_1ms":669,"lbm_write_time_us":30149,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:31.699949  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade): perf score=10.126437
I20260812 06:17:31.726818  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: FlushDeltaMemStoresOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.027s	user 0.011s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":11206,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":1500}
I20260812 06:17:31.727331  5649 maintenance_manager.cc:419] P 93c46c21c6a847038978fb82afda5bd4: Scheduling MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade): perf score=1.000000
I20260812 06:17:31.732888  5352 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.003s	sys 0.000s
I20260812 06:17:31.733563  5352 tablet_server.cc:179] TabletServer@127.5.58.1:0 shutting down...
I20260812 06:17:31.820226  5550 maintenance_manager.cc:643] P 93c46c21c6a847038978fb82afda5bd4: MajorDeltaCompactionOp(7a76ab6421164ea59dd77f02f7816ade) complete. Timing: real 0.093s	user 0.076s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":573,"lbm_read_time_us":6364,"lbm_reads_lt_1ms":367,"lbm_write_time_us":18815,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":129,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.820896  5352 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:31.821359  5352 tablet_replica.cc:333] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4: stopping tablet replica
I20260812 06:17:31.821585  5352 raft_consensus.cc:2243] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.821805  5352 raft_consensus.cc:2272] T 7a76ab6421164ea59dd77f02f7816ade P 93c46c21c6a847038978fb82afda5bd4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.837011  5352 tablet_server.cc:196] TabletServer@127.5.58.1:0 shutdown complete.
I20260812 06:17:31.852385  5352 master.cc:562] Master@127.5.58.62:45459 shutting down...
I20260812 06:17:31.855785  5352 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.855986  5352 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.856068  5352 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1b89c152f33840beba94450bb9fa7a5b: stopping tablet replica
I20260812 06:17:31.868299  5352 master.cc:584] Master@127.5.58.62:45459 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5317 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:31.939774  5352 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.58.62:33643
I20260812 06:17:31.940148  5352 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.942090  5707 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:31.942139  5709 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:31.942303  5352 server_base.cc:1061] running on GCE node
W20260812 06:17:31.942348  5712 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:31.942536  5352 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.942579  5352 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:31.942598  5352 hybrid_clock.cc:648] HybridClock initialized: now 1786515451942598 us; error 0 us; skew 500 ppm
I20260812 06:17:31.943392  5352 webserver.cc:533] Webserver started at http://127.5.58.62:40005/ using document root <none> and password file <none>
I20260812 06:17:31.943564  5352 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.943619  5352 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.943697  5352 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.944049  5352 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/master-0-root/instance:
uuid: "745718c06b7747b0b7d13058e6afd03c"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-pww0"
I20260812 06:17:31.945529  5352 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:31.946393  5719 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:31.946630  5352 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.946699  5352 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/master-0-root
uuid: "745718c06b7747b0b7d13058e6afd03c"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-pww0"
I20260812 06:17:31.946772  5352 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-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:31.959018  5352 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.959406  5352 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.963184  5352 rpc_server.cc:307] RPC server started. Bound to: 127.5.58.62:33643
I20260812 06:17:31.966280  5839 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.58.62:33643 every 8 connection(s)
I20260812 06:17:31.975127  5841 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:31.977090  5841 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c: Bootstrap starting.
I20260812 06:17:31.977903  5841 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.978988  5841 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c: No bootstrap required, opened a new log
I20260812 06:17:31.979403  5841 raft_consensus.cc:359] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER }
I20260812 06:17:31.979529  5841 raft_consensus.cc:385] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.979554  5841 raft_consensus.cc:740] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 745718c06b7747b0b7d13058e6afd03c, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.979709  5841 consensus_queue.cc:260] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [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: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER }
I20260812 06:17:31.979796  5841 raft_consensus.cc:399] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.979820  5841 raft_consensus.cc:493] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.979853  5841 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.980567  5841 raft_consensus.cc:515] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER }
I20260812 06:17:31.980697  5841 leader_election.cc:304] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [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: 745718c06b7747b0b7d13058e6afd03c; no voters: 
I20260812 06:17:31.980896  5841 leader_election.cc:290] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.981016  5849 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.981251  5849 raft_consensus.cc:697] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 1 LEADER]: Becoming Leader. State: Replica: 745718c06b7747b0b7d13058e6afd03c, State: Running, Role: LEADER
I20260812 06:17:31.981341  5841 sys_catalog.cc:565] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:31.981403  5849 consensus_queue.cc:237] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [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: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER }
I20260812 06:17:31.981846  5851 sys_catalog.cc:455] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "745718c06b7747b0b7d13058e6afd03c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER } }
I20260812 06:17:31.981869  5852 sys_catalog.cc:455] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 745718c06b7747b0b7d13058e6afd03c. Latest consensus state: current_term: 1 leader_uuid: "745718c06b7747b0b7d13058e6afd03c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745718c06b7747b0b7d13058e6afd03c" member_type: VOTER } }
I20260812 06:17:31.982014  5852 sys_catalog.cc:458] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.982574  5851 sys_catalog.cc:458] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.982654  5860 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:31.983559  5860 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:31.983779  5352 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:31.985345  5860 catalog_manager.cc:1383] Generated new cluster ID: 1a824a36f030444db6ed455d2ee13d2b
I20260812 06:17:31.985401  5860 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.991511  5860 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.992115  5860 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.998566  5860 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c: Generated new TSK 0
I20260812 06:17:31.998802  5860 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.999923  5352 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.001876  5889 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:32.001951  5886 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:32.001998  5352 server_base.cc:1061] running on GCE node
W20260812 06:17:32.001951  5885 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:32.002359  5352 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.002409  5352 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:32.002429  5352 hybrid_clock.cc:648] HybridClock initialized: now 1786515452002428 us; error 0 us; skew 500 ppm
I20260812 06:17:32.003296  5352 webserver.cc:533] Webserver started at http://127.5.58.1:35781/ using document root <none> and password file <none>
I20260812 06:17:32.003477  5352 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.003538  5352 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.003623  5352 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.003996  5352 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/instance:
uuid: "8a966001d97e4c25bafa20367223e49f"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-pww0"
I20260812 06:17:32.005573  5352 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:32.006610  5898 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:32.006873  5352 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.006951  5352 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root
uuid: "8a966001d97e4c25bafa20367223e49f"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-pww0"
I20260812 06:17:32.007028  5352 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-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:32.020520  5352 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.020962  5352 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.021286  5352 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:32.021795  5352 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:32.021839  5352 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.021888  5352 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:32.021922  5352 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.026093  5352 rpc_server.cc:307] RPC server started. Bound to: 127.5.58.1:37087
I20260812 06:17:32.026131  6024 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.58.1:37087 every 8 connection(s)
I20260812 06:17:32.034173  6025 heartbeater.cc:344] Connected to a master server at 127.5.58.62:33643
I20260812 06:17:32.034302  6025 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:32.034582  6025 heartbeater.cc:507] Master 127.5.58.62:33643 requested a full tablet report, sending...
I20260812 06:17:32.035291  5756 ts_manager.cc:194] Registered new tserver with Master: 8a966001d97e4c25bafa20367223e49f (127.5.58.1:37087)
I20260812 06:17:32.035351  5352 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008849909s
I20260812 06:17:32.036120  5756 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51840
I20260812 06:17:32.043082  5756 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51844:
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:32.052186  5965 tablet_service.cc:1511] Processing CreateTablet for tablet 7a670da109154145be77865e3ad68033 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4f2277f198d245bdb6ac5f2f1b6e3121]), partition=
I20260812 06:17:32.052475  5965 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7a670da109154145be77865e3ad68033. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.054637  6042 tablet_bootstrap.cc:492] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Bootstrap starting.
I20260812 06:17:32.055568  6042 tablet_bootstrap.cc:654] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.056718  6042 tablet_bootstrap.cc:492] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: No bootstrap required, opened a new log
I20260812 06:17:32.056802  6042 ts_tablet_manager.cc:1403] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:32.057219  6042 raft_consensus.cc:359] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a966001d97e4c25bafa20367223e49f" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 37087 } }
I20260812 06:17:32.057320  6042 raft_consensus.cc:385] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.057353  6042 raft_consensus.cc:740] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8a966001d97e4c25bafa20367223e49f, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.057493  6042 consensus_queue.cc:260] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [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: "8a966001d97e4c25bafa20367223e49f" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 37087 } }
I20260812 06:17:32.057581  6042 raft_consensus.cc:399] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.057621  6042 raft_consensus.cc:493] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.057680  6042 raft_consensus.cc:3060] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.058441  6042 raft_consensus.cc:515] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a966001d97e4c25bafa20367223e49f" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 37087 } }
I20260812 06:17:32.058584  6042 leader_election.cc:304] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [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: 8a966001d97e4c25bafa20367223e49f; no voters: 
I20260812 06:17:32.058795  6042 leader_election.cc:290] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.058984  6048 raft_consensus.cc:2804] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.059095  6042 ts_tablet_manager.cc:1434] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:32.059136  6025 heartbeater.cc:499] Master 127.5.58.62:33643 was elected leader, sending a full tablet report...
I20260812 06:17:32.059185  6048 raft_consensus.cc:697] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 1 LEADER]: Becoming Leader. State: Replica: 8a966001d97e4c25bafa20367223e49f, State: Running, Role: LEADER
I20260812 06:17:32.059324  6048 consensus_queue.cc:237] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [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: "8a966001d97e4c25bafa20367223e49f" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 37087 } }
I20260812 06:17:32.060860  5756 catalog_manager.cc:5719] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f reported cstate change: term changed from 0 to 1, leader changed from <none> to 8a966001d97e4c25bafa20367223e49f (127.5.58.1). New cstate: current_term: 1 leader_uuid: "8a966001d97e4c25bafa20367223e49f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a966001d97e4c25bafa20367223e49f" member_type: VOTER last_known_addr { host: "127.5.58.1" port: 37087 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:32.120924  5352 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:17:32.277000  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushMRSOp(7a670da109154145be77865e3ad68033): perf score=19.054940
I20260812 06:17:32.421259  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushMRSOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.144s	user 0.110s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":739,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34947,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:17:32.422217  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling LogGCOp(7a670da109154145be77865e3ad68033): free 20743880 bytes of WAL
I20260812 06:17:32.422549  5907 log_reader.cc:385] T 7a670da109154145be77865e3ad68033: removed 2 log segments from log reader
I20260812 06:17:32.422657  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000001 (ops 1-6)
I20260812 06:17:32.422740  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000002 (ops 7-11)
I20260812 06:17:32.427066  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: LogGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:32.427448  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:32.451570  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.024s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.452072  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033): 16821649 bytes on disk
I20260812 06:17:32.452540  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.452975  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:32.468534  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.469205  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:32.633906  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.164s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405562,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":492,"lbm_read_time_us":10283,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27557,"lbm_writes_lt_1ms":533,"mutex_wait_us":36,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":332,"threads_started":5,"update_count":2450}
I20260812 06:17:32.634418  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:32.682756  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.048s	user 0.023s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17543,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.683300  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:32.698534  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5536,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.699095  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:32.846632  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.147s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":11284,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25133,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:32.847965  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=12.110812
I20260812 06:17:32.882830  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.035s	user 0.030s	sys 0.001s Metrics: {"bytes_written":13497196,"delete_count":0,"lbm_write_time_us":14842,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1645}
I20260812 06:17:32.883342  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=1.196750
I20260812 06:17:32.893196  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":3495,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:17:32.893702  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.043561  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.150s	user 0.098s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713249,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":11601,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23407,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:17:33.044057  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:33.072515  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.028s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.073030  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.085764  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":500}
I20260812 06:17:33.086310  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.213336  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.127s	user 0.092s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":855,"lbm_read_time_us":7833,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23949,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:33.213934  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:33.252574  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.038s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14219,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.253160  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.263154  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.263972  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.383420  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.119s	user 0.100s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":8038,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23020,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.383939  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:33.427212  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.043s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14338,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.427835  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.438259  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.439283  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.564759  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.125s	user 0.095s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":683,"lbm_read_time_us":9491,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:33.565351  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:33.612993  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.047s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12976,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.613602  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.623986  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.624457  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushMRSOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.665230  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushMRSOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.041s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1234,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1806,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:33.665925  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling LogGCOp(7a670da109154145be77865e3ad68033): free 120553381 bytes of WAL
I20260812 06:17:33.666157  5907 log_reader.cc:385] T 7a670da109154145be77865e3ad68033: removed 12 log segments from log reader
I20260812 06:17:33.666208  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000003 (ops 12-16)
I20260812 06:17:33.666237  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000004 (ops 17-20)
I20260812 06:17:33.666270  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000005 (ops 21-25)
I20260812 06:17:33.666292  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000006 (ops 26-30)
I20260812 06:17:33.666325  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000007 (ops 31-35)
I20260812 06:17:33.666358  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000008 (ops 36-40)
I20260812 06:17:33.666390  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000009 (ops 41-44)
I20260812 06:17:33.666422  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000010 (ops 45-49)
I20260812 06:17:33.666453  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000011 (ops 50-54)
I20260812 06:17:33.666486  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000012 (ops 55-59)
I20260812 06:17:33.666517  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000013 (ops 60-64)
I20260812 06:17:33.666546  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000014 (ops 65-69)
I20260812 06:17:33.685177  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: LogGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.019s	user 0.001s	sys 0.017s Metrics: {}
I20260812 06:17:33.685552  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033): 462 bytes on disk
I20260812 06:17:33.686020  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.686584  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=3.181125
I20260812 06:17:33.709043  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.022s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.709489  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.718950  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3333,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.719483  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:33.903653  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.184s	user 0.128s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":203,"lbm_read_time_us":12559,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28651,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:17:33.904274  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:33.958024  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.054s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.958561  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:33.969172  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.969713  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:34.135558  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.166s	user 0.115s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":10404,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26975,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:34.136153  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:34.194916  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.059s	user 0.023s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16834,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.195668  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:34.206255  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.206809  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:34.381469  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.174s	user 0.112s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":449,"lbm_read_time_us":12756,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28766,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:17:34.382084  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=11.118625
I20260812 06:17:34.417281  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.035s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14441,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.418071  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:34.439141  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.021s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.439776  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:34.590065  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.150s	user 0.118s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":11105,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21387,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.590729  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=11.118625
I20260812 06:17:34.629634  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.039s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16802,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.630208  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:34.641431  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.641944  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:34.762872  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.121s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":7533,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23144,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":62976,"update_count":2000}
I20260812 06:17:34.763624  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:34.803578  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.040s	user 0.025s	sys 0.005s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12304,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.804158  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:34.820123  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.820739  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:34.946162  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.125s	user 0.112s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":10002,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21831,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:34.946790  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:34.995664  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.049s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14857,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.996382  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:35.011957  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.012547  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushMRSOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:35.057166  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushMRSOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.044s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1209,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1935,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:35.057981  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling LogGCOp(7a670da109154145be77865e3ad68033): free 120553380 bytes of WAL
I20260812 06:17:35.058266  5907 log_reader.cc:385] T 7a670da109154145be77865e3ad68033: removed 12 log segments from log reader
I20260812 06:17:35.058331  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000015 (ops 70-74)
I20260812 06:17:35.058375  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000016 (ops 75-78)
I20260812 06:17:35.058408  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000017 (ops 79-83)
I20260812 06:17:35.058434  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000018 (ops 84-88)
I20260812 06:17:35.058465  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000019 (ops 89-92)
I20260812 06:17:35.058491  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000020 (ops 93-97)
I20260812 06:17:35.058522  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000021 (ops 98-102)
I20260812 06:17:35.058552  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000022 (ops 103-107)
I20260812 06:17:35.058583  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000023 (ops 108-112)
I20260812 06:17:35.058605  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000024 (ops 113-117)
I20260812 06:17:35.058629  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000025 (ops 118-122)
I20260812 06:17:35.058658  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000026 (ops 123-127)
I20260812 06:17:35.079120  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: LogGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:35.079599  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033): 448 bytes on disk
I20260812 06:17:35.080068  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.080832  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=3.181125
I20260812 06:17:35.106912  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5433,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.107357  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:35.116899  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3251,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.117452  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:35.322518  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.205s	user 0.133s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":255,"lbm_read_time_us":13450,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33934,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:35.323190  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:35.382546  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.059s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21608,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.383167  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:35.399576  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.016s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.400036  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:35.573410  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.173s	user 0.117s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":550,"lbm_read_time_us":12351,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27468,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:17:35.573938  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:35.632699  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.059s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18309,"lbm_writes_lt_1ms":403,"mutex_wait_us":21,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.633352  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:35.648864  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.649434  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:35.811656  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.162s	user 0.110s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":528,"lbm_read_time_us":12289,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26126,"lbm_writes_lt_1ms":543,"mutex_wait_us":264,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:17:35.812311  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:35.846891  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.034s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":13225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.847620  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:35.868986  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.021s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.869513  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.018719  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.149s	user 0.087s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":10172,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23075,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:36.019318  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:36.050451  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.031s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12581,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.050962  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:36.062552  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.063417  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.181653  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.118s	user 0.104s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1144,"lbm_read_time_us":8973,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20894,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:17:36.182266  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:36.226423  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.044s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14688,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.227082  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:36.238782  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.239499  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.352880  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.113s	user 0.089s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1011,"lbm_read_time_us":8151,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21040,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:17:36.353520  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=10.126437
I20260812 06:17:36.402448  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.049s	user 0.010s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.403124  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=2.188937
I20260812 06:17:36.413515  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3803,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.413988  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushMRSOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.441135  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushMRSOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1361,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1374,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:36.441871  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.605602  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.164s	user 0.093s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":10029,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25825,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":52096,"update_count":2000}
I20260812 06:17:36.606194  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling LogGCOp(7a670da109154145be77865e3ad68033): free 108535684 bytes of WAL
I20260812 06:17:36.606637  5907 log_reader.cc:385] T 7a670da109154145be77865e3ad68033: removed 11 log segments from log reader
I20260812 06:17:36.606693  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000027 (ops 128-132)
I20260812 06:17:36.606729  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000028 (ops 133-137)
I20260812 06:17:36.606758  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000029 (ops 138-142)
I20260812 06:17:36.606835  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000030 (ops 143-146)
I20260812 06:17:36.606873  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000031 (ops 147-151)
I20260812 06:17:36.606927  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000032 (ops 152-156)
I20260812 06:17:36.606959  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000033 (ops 157-160)
I20260812 06:17:36.607005  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000034 (ops 161-165)
I20260812 06:17:36.607034  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000035 (ops 166-170)
I20260812 06:17:36.607086  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000036 (ops 171-175)
I20260812 06:17:36.607126  5907 log.cc:1079] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: Deleting log segment in path: /tmp/dist-test-taskl8ZYMo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446612182-5352-0/minicluster-data/ts-0-root/wals/7a670da109154145be77865e3ad68033/wal-000000037 (ops 176-180)
I20260812 06:17:36.630424  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: LogGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:36.631050  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033): 447 bytes on disk
I20260812 06:17:36.631642  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: UndoDeltaBlockGCOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.632449  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=15.087375
I20260812 06:17:36.695433  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.063s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16820140,"delete_count":0,"lbm_write_time_us":20922,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:36.695992  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=6.157687
I20260812 06:17:36.721076  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.025s	user 0.012s	sys 0.011s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":7471,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:36.721738  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.884321  5352 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.763s	user 1.731s	sys 0.142s
I20260812 06:17:36.906633  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.185s	user 0.109s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918093,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11714,"lbm_reads_lt_1ms":660,"lbm_write_time_us":33310,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3000}
I20260812 06:17:36.907315  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033): perf score=14.095187
I20260812 06:17:36.953636  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: FlushDeltaMemStoresOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.046s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409940,"delete_count":0,"lbm_write_time_us":18236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.954210  6026 maintenance_manager.cc:419] P 8a966001d97e4c25bafa20367223e49f: Scheduling MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033): perf score=1.000000
I20260812 06:17:36.957145  5352 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:17:36.957772  5352 tablet_server.cc:179] TabletServer@127.5.58.1:0 shutting down...
I20260812 06:17:37.069036  5907 maintenance_manager.cc:643] P 8a966001d97e4c25bafa20367223e49f: MajorDeltaCompactionOp(7a670da109154145be77865e3ad68033) complete. Timing: real 0.113s	user 0.088s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713191,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1260,"lbm_read_time_us":8518,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23452,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":83,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:37.069677  5352 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:37.069921  5352 tablet_replica.cc:333] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f: stopping tablet replica
I20260812 06:17:37.070076  5352 raft_consensus.cc:2243] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.070247  5352 raft_consensus.cc:2272] T 7a670da109154145be77865e3ad68033 P 8a966001d97e4c25bafa20367223e49f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.085377  5352 tablet_server.cc:196] TabletServer@127.5.58.1:0 shutdown complete.
I20260812 06:17:37.107628  5352 master.cc:562] Master@127.5.58.62:33643 shutting down...
I20260812 06:17:37.110638  5352 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.110834  5352 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.110908  5352 tablet_replica.cc:333] T 00000000000000000000000000000000 P 745718c06b7747b0b7d13058e6afd03c: stopping tablet replica
I20260812 06:17:37.123440  5352 master.cc:584] Master@127.5.58.62:33643 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5256 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10574 ms total)

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