[==========] 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:19:24.582504 26380 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.195.62:35573
I20260812 06:19:24.583359 26380 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:19:24.583878 26380 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.589550 26389 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:19:24.589627 26392 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:19:24.589730 26380 server_base.cc:1061] running on GCE node
W20260812 06:19:24.589737 26390 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:19:24.590201 26380 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.590291 26380 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:19:24.590332 26380 hybrid_clock.cc:648] HybridClock initialized: now 1786515564590328 us; error 0 us; skew 500 ppm
I20260812 06:19:24.591810 26380 webserver.cc:533] Webserver started at http://127.25.195.62:39719/ using document root <none> and password file <none>
I20260812 06:19:24.592253 26380 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.592309 26380 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.592501 26380 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.593914 26380 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/master-0-root/instance:
uuid: "a72512746b5c45dd908f91e1264ba19c"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-6zbq"
I20260812 06:19:24.596915 26380 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:19:24.598728 26403 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:19:24.599574 26380 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.599673 26380 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/master-0-root
uuid: "a72512746b5c45dd908f91e1264ba19c"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-6zbq"
I20260812 06:19:24.599747 26380 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-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:19:24.614045 26380 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.614586 26380 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:19:24.614718 26380 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:24.621273 26496 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.195.62:35573 every 8 connection(s)
I20260812 06:19:24.621279 26380 rpc_server.cc:307] RPC server started. Bound to: 127.25.195.62:35573
I20260812 06:19:24.623266 26498 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:19:24.628003 26498 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: Bootstrap starting.
I20260812 06:19:24.630074 26498 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:24.630879 26498 log.cc:826] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:24.632261 26498 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: No bootstrap required, opened a new log
I20260812 06:19:24.634743 26498 raft_consensus.cc:359] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER }
I20260812 06:19:24.634887 26498 raft_consensus.cc:385] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:24.634932 26498 raft_consensus.cc:740] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a72512746b5c45dd908f91e1264ba19c, State: Initialized, Role: FOLLOWER
I20260812 06:19:24.635397 26498 consensus_queue.cc:260] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [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: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER }
I20260812 06:19:24.635519 26498 raft_consensus.cc:399] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:24.635561 26498 raft_consensus.cc:493] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:24.635643 26498 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.636279 26498 raft_consensus.cc:515] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER }
I20260812 06:19:24.636626 26498 leader_election.cc:304] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [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: a72512746b5c45dd908f91e1264ba19c; no voters: 
I20260812 06:19:24.636853 26498 leader_election.cc:290] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.636977 26504 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.637166 26504 raft_consensus.cc:697] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 1 LEADER]: Becoming Leader. State: Replica: a72512746b5c45dd908f91e1264ba19c, State: Running, Role: LEADER
I20260812 06:19:24.637514 26504 consensus_queue.cc:237] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [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: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER }
I20260812 06:19:24.637655 26498 sys_catalog.cc:565] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:24.639247 26505 sys_catalog.cc:455] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a72512746b5c45dd908f91e1264ba19c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER } }
I20260812 06:19:24.639237 26506 sys_catalog.cc:455] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [sys.catalog]: SysCatalogTable state changed. Reason: New leader a72512746b5c45dd908f91e1264ba19c. Latest consensus state: current_term: 1 leader_uuid: "a72512746b5c45dd908f91e1264ba19c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a72512746b5c45dd908f91e1264ba19c" member_type: VOTER } }
I20260812 06:19:24.639369 26505 sys_catalog.cc:458] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:24.639369 26506 sys_catalog.cc:458] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:24.639720 26380 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:24.639791 26522 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:24.641732 26522 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:24.645882 26522 catalog_manager.cc:1383] Generated new cluster ID: 70766c90d84044fd9addd5c4d9a91d74
I20260812 06:19:24.645941 26522 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:24.671034 26522 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:24.672111 26522 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:24.680213 26522 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: Generated new TSK 0
I20260812 06:19:24.680837 26522 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:24.704180 26380 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.706506 26528 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:19:24.706496 26530 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:24.706676 26533 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:19:24.706789 26380 server_base.cc:1061] running on GCE node
I20260812 06:19:24.707012 26380 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.707059 26380 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:19:24.707074 26380 hybrid_clock.cc:648] HybridClock initialized: now 1786515564707074 us; error 0 us; skew 500 ppm
I20260812 06:19:24.707890 26380 webserver.cc:533] Webserver started at http://127.25.195.1:41937/ using document root <none> and password file <none>
I20260812 06:19:24.708048 26380 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.708094 26380 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.708194 26380 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.708536 26380 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/instance:
uuid: "e769d36f361d4eaf96f0532cbfd1a351"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-6zbq"
I20260812 06:19:24.709906 26380 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:24.710908 26545 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:19:24.711135 26380 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:24.711201 26380 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root
uuid: "e769d36f361d4eaf96f0532cbfd1a351"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-6zbq"
I20260812 06:19:24.711270 26380 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-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:19:24.723932 26380 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.724295 26380 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:24.724684 26380 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:24.725476 26380 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:24.725528 26380 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.725571 26380 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:24.725601 26380 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:24.731606 26380 rpc_server.cc:307] RPC server started. Bound to: 127.25.195.1:38913
I20260812 06:19:24.731662 26657 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.195.1:38913 every 8 connection(s)
I20260812 06:19:24.744701 26658 heartbeater.cc:344] Connected to a master server at 127.25.195.62:35573
I20260812 06:19:24.744913 26658 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:24.745294 26658 heartbeater.cc:507] Master 127.25.195.62:35573 requested a full tablet report, sending...
I20260812 06:19:24.746575 26432 ts_manager.cc:194] Registered new tserver with Master: e769d36f361d4eaf96f0532cbfd1a351 (127.25.195.1:38913)
I20260812 06:19:24.746665 26380 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014480459s
I20260812 06:19:24.747670 26432 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44614
I20260812 06:19:24.755245 26432 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44624:
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:19:24.768317 26596 tablet_service.cc:1511] Processing CreateTablet for tablet ad47b0803dca49b2b132fbed2547eae3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f19a843ac6974d36802a47b92bc73c1b]), partition=
I20260812 06:19:24.768748 26596 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ad47b0803dca49b2b132fbed2547eae3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:24.770766 26680 tablet_bootstrap.cc:492] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Bootstrap starting.
I20260812 06:19:24.771603 26680 tablet_bootstrap.cc:654] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:24.772974 26680 tablet_bootstrap.cc:492] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: No bootstrap required, opened a new log
I20260812 06:19:24.773064 26680 ts_tablet_manager.cc:1403] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:24.773514 26680 raft_consensus.cc:359] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e769d36f361d4eaf96f0532cbfd1a351" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 38913 } }
I20260812 06:19:24.773609 26680 raft_consensus.cc:385] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:24.773641 26680 raft_consensus.cc:740] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e769d36f361d4eaf96f0532cbfd1a351, State: Initialized, Role: FOLLOWER
I20260812 06:19:24.773772 26680 consensus_queue.cc:260] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [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: "e769d36f361d4eaf96f0532cbfd1a351" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 38913 } }
I20260812 06:19:24.773859 26680 raft_consensus.cc:399] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:24.773886 26680 raft_consensus.cc:493] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:24.773933 26680 raft_consensus.cc:3060] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.774657 26680 raft_consensus.cc:515] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e769d36f361d4eaf96f0532cbfd1a351" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 38913 } }
I20260812 06:19:24.774771 26680 leader_election.cc:304] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [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: e769d36f361d4eaf96f0532cbfd1a351; no voters: 
I20260812 06:19:24.774945 26680 leader_election.cc:290] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.775048 26682 raft_consensus.cc:2804] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.775287 26680 ts_tablet_manager.cc:1434] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:24.775588 26658 heartbeater.cc:499] Master 127.25.195.62:35573 was elected leader, sending a full tablet report...
I20260812 06:19:24.775306 26682 raft_consensus.cc:697] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 1 LEADER]: Becoming Leader. State: Replica: e769d36f361d4eaf96f0532cbfd1a351, State: Running, Role: LEADER
I20260812 06:19:24.776072 26682 consensus_queue.cc:237] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [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: "e769d36f361d4eaf96f0532cbfd1a351" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 38913 } }
I20260812 06:19:24.778406 26432 catalog_manager.cc:5719] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 reported cstate change: term changed from 0 to 1, leader changed from <none> to e769d36f361d4eaf96f0532cbfd1a351 (127.25.195.1). New cstate: current_term: 1 leader_uuid: "e769d36f361d4eaf96f0532cbfd1a351" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e769d36f361d4eaf96f0532cbfd1a351" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 38913 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:24.833148 26380 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.013s	sys 0.011s
I20260812 06:19:24.982596 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3): perf score=23.023690
I20260812 06:19:25.200789 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.218s	user 0.136s	sys 0.070s Metrics: {"bytes_written":16820148,"cfile_init":1,"compiler_manager_pool.queue_time_us":197,"delete_count":0,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":708,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":53259,"lbm_writes_lt_1ms":967,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":107,"threads_started":1,"update_count":2050}
I20260812 06:19:25.201898 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling LogGCOp(ad47b0803dca49b2b132fbed2547eae3): free 20743880 bytes of WAL
I20260812 06:19:25.202198 26557 log_reader.cc:385] T ad47b0803dca49b2b132fbed2547eae3: removed 2 log segments from log reader
I20260812 06:19:25.202270 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000001 (ops 1-6)
I20260812 06:19:25.202330 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000002 (ops 7-11)
I20260812 06:19:25.207289 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: LogGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:25.207607 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=6.157687
I20260812 06:19:25.236129 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.028s	user 0.008s	sys 0.014s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9769,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:25.236867 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:25.416023 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.179s	user 0.102s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":12130,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30242,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":256,"threads_started":5,"update_count":3000}
I20260812 06:19:25.416476 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3): 20513815 bytes on disk
I20260812 06:19:25.416941 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.417326 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:25.462194 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19559,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.462679 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:25.598461 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.136s	user 0.084s	sys 0.046s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":895,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22168,"lbm_writes_lt_1ms":443,"mutex_wait_us":254,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:25.598994 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=11.118625
I20260812 06:19:25.632539 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.033s	user 0.015s	sys 0.014s Metrics: {"bytes_written":13004907,"delete_count":0,"lbm_write_time_us":13506,"lbm_writes_lt_1ms":320,"reinsert_count":0,"update_count":1585}
I20260812 06:19:25.633091 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:25.647850 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.015s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3410,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:19:25.648224 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:25.657181 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3427,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.657554 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:25.827489 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.170s	user 0.090s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815791,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":658,"lbm_read_time_us":9048,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26292,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:19:25.827987 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:25.870792 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.043s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20271,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.871165 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:25.883008 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.883617 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:26.028620 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.145s	user 0.099s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":8095,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29192,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:19:26.029124 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:26.072085 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.043s	user 0.021s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.072517 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:26.082294 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.082937 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:26.220110 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.137s	user 0.107s	sys 0.020s 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":149,"lbm_read_time_us":8982,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25962,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:26.220698 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:26.267395 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20034,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.268024 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:26.285468 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.286003 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:26.316895 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1121,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1908,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:26.317862 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling LogGCOp(ad47b0803dca49b2b132fbed2547eae3): free 124710306 bytes of WAL
I20260812 06:19:26.318122 26557 log_reader.cc:385] T ad47b0803dca49b2b132fbed2547eae3: removed 12 log segments from log reader
I20260812 06:19:26.318236 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000003 (ops 12-16)
I20260812 06:19:26.318310 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000004 (ops 17-21)
I20260812 06:19:26.318430 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000005 (ops 22-26)
I20260812 06:19:26.318492 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000006 (ops 27-31)
I20260812 06:19:26.318552 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000007 (ops 32-36)
I20260812 06:19:26.318589 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000008 (ops 37-41)
I20260812 06:19:26.318639 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000009 (ops 42-46)
I20260812 06:19:26.318675 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000010 (ops 47-51)
I20260812 06:19:26.318738 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000011 (ops 52-56)
I20260812 06:19:26.318775 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000012 (ops 57-61)
I20260812 06:19:26.318797 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000013 (ops 62-66)
I20260812 06:19:26.318821 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000014 (ops 67-71)
I20260812 06:19:26.339685 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: LogGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.022s	user 0.002s	sys 0.018s Metrics: {}
I20260812 06:19:26.340116 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3): 482 bytes on disk
I20260812 06:19:26.340497 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.340955 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=6.157687
I20260812 06:19:26.368813 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.028s	user 0.009s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8160,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:26.369225 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:26.574189 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.205s	user 0.147s	sys 0.052s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020630,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2086,"lbm_read_time_us":13426,"lbm_reads_lt_1ms":765,"lbm_write_time_us":35006,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:26.574747 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=18.063937
I20260812 06:19:26.627426 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.052s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22814,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:26.627859 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:26.642457 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.014s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.643003 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:26.804620 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.161s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":774,"lbm_read_time_us":12605,"lbm_reads_lt_1ms":672,"lbm_write_time_us":27625,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":60032,"update_count":3000}
I20260812 06:19:26.805096 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:26.855276 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.050s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17578,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.855741 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:26.865235 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.865620 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:27.036113 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.170s	user 0.134s	sys 0.028s 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":548,"lbm_read_time_us":11736,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27463,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:19:27.036657 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:27.092566 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.056s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22205,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.093111 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:27.102749 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.103174 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:27.268649 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.165s	user 0.112s	sys 0.053s 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":151,"lbm_read_time_us":11181,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29153,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:27.269284 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=11.118625
I20260812 06:19:27.309703 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12512611,"delete_count":0,"lbm_write_time_us":16813,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":307,"reinsert_count":0,"update_count":1525}
I20260812 06:19:27.310305 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:27.339808 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.029s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:27.340301 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:27.355216 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.355759 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:27.527581 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.172s	user 0.127s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1006,"lbm_read_time_us":12549,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28820,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:27.528115 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:27.570686 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17827,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.571143 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:27.588755 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.017s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.589191 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:27.766794 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.177s	user 0.114s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1222,"lbm_read_time_us":11718,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26767,"lbm_writes_lt_1ms":543,"mutex_wait_us":452,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:19:27.767279 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:27.813793 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.046s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19107,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.814325 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:27.824404 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.825042 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:27.862059 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.037s	user 0.027s	sys 0.006s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":157,"dirs.run_wall_time_us":947,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1440,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:27.862840 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling LogGCOp(ad47b0803dca49b2b132fbed2547eae3): free 133024402 bytes of WAL
I20260812 06:19:27.863077 26557 log_reader.cc:385] T ad47b0803dca49b2b132fbed2547eae3: removed 13 log segments from log reader
I20260812 06:19:27.863126 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000015 (ops 72-76)
I20260812 06:19:27.863153 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000016 (ops 77-80)
I20260812 06:19:27.863188 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000017 (ops 81-85)
I20260812 06:19:27.863224 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000018 (ops 86-90)
I20260812 06:19:27.863242 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000019 (ops 91-95)
I20260812 06:19:27.863268 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000020 (ops 96-100)
I20260812 06:19:27.863301 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000021 (ops 101-105)
I20260812 06:19:27.863332 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000022 (ops 106-110)
I20260812 06:19:27.863363 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000023 (ops 111-115)
I20260812 06:19:27.863400 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000024 (ops 116-120)
I20260812 06:19:27.863431 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000025 (ops 121-125)
I20260812 06:19:27.863462 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000026 (ops 126-130)
I20260812 06:19:27.863493 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000027 (ops 131-135)
I20260812 06:19:27.886281 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: LogGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.023s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:27.886745 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=3.181125
I20260812 06:19:27.901409 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:27.901775 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling LogGCOp(ad47b0803dca49b2b132fbed2547eae3): free 12017954 bytes of WAL
I20260812 06:19:27.901950 26557 log_reader.cc:385] T ad47b0803dca49b2b132fbed2547eae3: removed 1 log segments from log reader
I20260812 06:19:27.901993 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000028 (ops 136-140)
I20260812 06:19:27.903964 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: LogGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:27.904383 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:28.098670 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.194s	user 0.132s	sys 0.062s Metrics: {"cfile_cache_miss":643,"cfile_cache_miss_bytes":29328455,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":532,"lbm_read_time_us":13559,"lbm_reads_lt_1ms":675,"lbm_write_time_us":34333,"lbm_writes_lt_1ms":653,"mutex_wait_us":344,"peak_mem_usage":75952822,"reinsert_count":0,"spinlock_wait_cycles":14080,"thread_start_us":70,"threads_started":1,"update_count":3050}
I20260812 06:19:28.099231 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:28.149592 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.050s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.150153 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3): 492 bytes on disk
I20260812 06:19:28.150590 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3) 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:19:28.151219 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:28.170276 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.170631 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:28.179126 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3268,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.179524 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:28.362035 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.182s	user 0.134s	sys 0.048s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28507962,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":248,"lbm_read_time_us":13175,"lbm_reads_lt_1ms":663,"lbm_write_time_us":31198,"lbm_writes_lt_1ms":633,"mutex_wait_us":22,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2950}
I20260812 06:19:28.362571 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:28.414382 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.052s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20620,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.414836 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:28.424264 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.000s	sys 0.008s 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:19:28.424633 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:28.593837 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.169s	user 0.133s	sys 0.029s 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":104,"lbm_read_time_us":12728,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27988,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:19:28.594386 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:28.649947 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.055s	user 0.013s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18479,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.650476 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:28.665220 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.665684 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:28.830655 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.165s	user 0.114s	sys 0.049s 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":873,"lbm_read_time_us":11547,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27278,"lbm_writes_lt_1ms":543,"mutex_wait_us":288,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:19:28.831266 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=11.118625
I20260812 06:19:28.865000 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.034s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14137,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:28.865732 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:28.886436 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.020s	user 0.013s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4984,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:19:28.886885 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:29.034025 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.147s	user 0.091s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":10411,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22702,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:29.034612 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=14.095187
I20260812 06:19:29.081364 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.047s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.081887 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:29.091109 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.091650 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:29.227844 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.136s	user 0.095s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":141,"lbm_read_time_us":10395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26395,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:29.228389 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=11.118625
I20260812 06:19:29.257802 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.029s	user 0.019s	sys 0.007s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":12697,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.258365 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:29.281214 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.023s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.281697 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:29.290994 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.291437 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:29.318814 26380 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.486s	user 1.620s	sys 0.136s
I20260812 06:19:29.320626 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushMRSOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1297,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:29.321290 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling LogGCOp(ad47b0803dca49b2b132fbed2547eae3): free 121006692 bytes of WAL
I20260812 06:19:29.321503 26557 log_reader.cc:385] T ad47b0803dca49b2b132fbed2547eae3: removed 12 log segments from log reader
I20260812 06:19:29.321547 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000029 (ops 141-145)
I20260812 06:19:29.321575 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000030 (ops 146-150)
I20260812 06:19:29.321609 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000031 (ops 151-155)
I20260812 06:19:29.321642 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000032 (ops 156-160)
I20260812 06:19:29.321676 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000033 (ops 161-165)
I20260812 06:19:29.321708 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000034 (ops 166-170)
I20260812 06:19:29.321740 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000035 (ops 171-175)
I20260812 06:19:29.321772 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000036 (ops 176-180)
I20260812 06:19:29.321805 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000037 (ops 181-185)
I20260812 06:19:29.321837 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000038 (ops 186-190)
I20260812 06:19:29.321869 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000039 (ops 191-194)
I20260812 06:19:29.321903 26557 log.cc:1079] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/ad47b0803dca49b2b132fbed2547eae3/wal-000000040 (ops 195-199)
I20260812 06:19:29.343088 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: LogGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:29.343411 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3): 483 bytes on disk
I20260812 06:19:29.343792 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: UndoDeltaBlockGCOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.344269 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3): perf score=2.188937
I20260812 06:19:29.353447 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: FlushDeltaMemStoresOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.353770 26660 maintenance_manager.cc:419] P e769d36f361d4eaf96f0532cbfd1a351: Scheduling MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3): perf score=1.000000
I20260812 06:19:29.370282 26380 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.051s	user 0.001s	sys 0.000s
I20260812 06:19:29.370893 26380 tablet_server.cc:179] TabletServer@127.25.195.1:0 shutting down...
I20260812 06:19:29.466857 26557 maintenance_manager.cc:643] P e769d36f361d4eaf96f0532cbfd1a351: MajorDeltaCompactionOp(ad47b0803dca49b2b132fbed2547eae3) complete. Timing: real 0.113s	user 0.085s	sys 0.028s Metrics: {"cfile_cache_hit":533,"cfile_cache_hit_bytes":24815798,"cfile_cache_miss":101,"cfile_cache_miss_bytes":4102530,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":218,"lbm_read_time_us":1583,"lbm_reads_lt_1ms":113,"lbm_write_time_us":26140,"lbm_writes_lt_1ms":643,"mutex_wait_us":18,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:19:29.468014 26380 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:29.468441 26380 tablet_replica.cc:333] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351: stopping tablet replica
I20260812 06:19:29.468693 26380 raft_consensus.cc:2243] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.468910 26380 raft_consensus.cc:2272] T ad47b0803dca49b2b132fbed2547eae3 P e769d36f361d4eaf96f0532cbfd1a351 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.484025 26380 tablet_server.cc:196] TabletServer@127.25.195.1:0 shutdown complete.
I20260812 06:19:29.517621 26380 master.cc:562] Master@127.25.195.62:35573 shutting down...
I20260812 06:19:29.521183 26380 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.521314 26380 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.521384 26380 tablet_replica.cc:333] T 00000000000000000000000000000000 P a72512746b5c45dd908f91e1264ba19c: stopping tablet replica
I20260812 06:19:29.533167 26380 master.cc:584] Master@127.25.195.62:35573 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5021 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:29.604169 26380 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.195.62:43373
I20260812 06:19:29.604588 26380 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.606436 26713 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:19:29.606483 26380 server_base.cc:1061] running on GCE node
W20260812 06:19:29.606503 26715 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:19:29.606530 26712 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:19:29.606786 26380 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.606828 26380 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:19:29.606848 26380 hybrid_clock.cc:648] HybridClock initialized: now 1786515569606847 us; error 0 us; skew 500 ppm
I20260812 06:19:29.607580 26380 webserver.cc:533] Webserver started at http://127.25.195.62:42963/ using document root <none> and password file <none>
I20260812 06:19:29.607725 26380 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.607774 26380 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.607844 26380 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.608199 26380 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/master-0-root/instance:
uuid: "0771664c1f944b40adef636bd66f38b7"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-6zbq"
I20260812 06:19:29.609526 26380 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:29.610322 26725 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:19:29.611047 26380 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:29.611116 26380 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/master-0-root
uuid: "0771664c1f944b40adef636bd66f38b7"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-6zbq"
I20260812 06:19:29.611188 26380 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-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:19:29.616149 26380 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.616430 26380 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.620019 26380 rpc_server.cc:307] RPC server started. Bound to: 127.25.195.62:43373
I20260812 06:19:29.626124 26819 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.195.62:43373 every 8 connection(s)
I20260812 06:19:29.629061 26821 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:19:29.632818 26821 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7: Bootstrap starting.
I20260812 06:19:29.633538 26821 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.634420 26821 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7: No bootstrap required, opened a new log
I20260812 06:19:29.634783 26821 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER }
I20260812 06:19:29.634860 26821 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.634894 26821 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0771664c1f944b40adef636bd66f38b7, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.635020 26821 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [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: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER }
I20260812 06:19:29.635085 26821 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.635120 26821 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.635169 26821 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.635782 26821 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER }
I20260812 06:19:29.635897 26821 leader_election.cc:304] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [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: 0771664c1f944b40adef636bd66f38b7; no voters: 
I20260812 06:19:29.636063 26821 leader_election.cc:290] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.636135 26825 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.636332 26825 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 1 LEADER]: Becoming Leader. State: Replica: 0771664c1f944b40adef636bd66f38b7, State: Running, Role: LEADER
I20260812 06:19:29.636472 26821 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:29.636462 26825 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [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: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER }
I20260812 06:19:29.636863 26828 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0771664c1f944b40adef636bd66f38b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER } }
I20260812 06:19:29.636968 26828 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.636878 26829 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0771664c1f944b40adef636bd66f38b7. Latest consensus state: current_term: 1 leader_uuid: "0771664c1f944b40adef636bd66f38b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0771664c1f944b40adef636bd66f38b7" member_type: VOTER } }
I20260812 06:19:29.637089 26829 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.637539 26835 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:29.638232 26835 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:29.638368 26380 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:29.639902 26835 catalog_manager.cc:1383] Generated new cluster ID: 910f679bd1204d85b4fad650d368ac5a
I20260812 06:19:29.639953 26835 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:29.646130 26835 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:29.646656 26835 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:29.655905 26835 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7: Generated new TSK 0
I20260812 06:19:29.656039 26835 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:29.670467 26380 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.672005 26863 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:19:29.672092 26865 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:19:29.672152 26380 server_base.cc:1061] running on GCE node
W20260812 06:19:29.672092 26870 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:19:29.672371 26380 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.672423 26380 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:19:29.672444 26380 hybrid_clock.cc:648] HybridClock initialized: now 1786515569672444 us; error 0 us; skew 500 ppm
I20260812 06:19:29.673179 26380 webserver.cc:533] Webserver started at http://127.25.195.1:37525/ using document root <none> and password file <none>
I20260812 06:19:29.673329 26380 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.673374 26380 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.673440 26380 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.673758 26380 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/instance:
uuid: "bb881748602c40d188598b433e2074f5"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-6zbq"
I20260812 06:19:29.675108 26380 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:29.675904 26884 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:19:29.676086 26380 fs_manager.cc:730] Time spent opening block manager: real 0.000s	user 0.000s	sys 0.001s
I20260812 06:19:29.676146 26380 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root
uuid: "bb881748602c40d188598b433e2074f5"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-6zbq"
I20260812 06:19:29.676208 26380 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-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:19:29.688939 26380 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.689205 26380 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.689445 26380 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:29.689827 26380 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:29.689863 26380 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.689904 26380 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:29.689934 26380 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.693809 26380 rpc_server.cc:307] RPC server started. Bound to: 127.25.195.1:36457
I20260812 06:19:29.693856 26988 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.195.1:36457 every 8 connection(s)
I20260812 06:19:29.698107 26989 heartbeater.cc:344] Connected to a master server at 127.25.195.62:43373
I20260812 06:19:29.698191 26989 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:29.698383 26989 heartbeater.cc:507] Master 127.25.195.62:43373 requested a full tablet report, sending...
I20260812 06:19:29.698927 26750 ts_manager.cc:194] Registered new tserver with Master: bb881748602c40d188598b433e2074f5 (127.25.195.1:36457)
I20260812 06:19:29.699585 26750 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58364
I20260812 06:19:29.699661 26380 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005497891s
I20260812 06:19:29.705394 26750 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58380:
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:19:29.712687 26934 tablet_service.cc:1511] Processing CreateTablet for tablet bed8069140634f9f860c1fbe550c0b25 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4f1c5fcb61074e66a18402f3b6e0cb5f]), partition=
I20260812 06:19:29.712906 26934 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bed8069140634f9f860c1fbe550c0b25. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:29.714573 27012 tablet_bootstrap.cc:492] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Bootstrap starting.
I20260812 06:19:29.715377 27012 tablet_bootstrap.cc:654] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.716282 27012 tablet_bootstrap.cc:492] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: No bootstrap required, opened a new log
I20260812 06:19:29.716359 27012 ts_tablet_manager.cc:1403] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:29.716710 27012 raft_consensus.cc:359] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb881748602c40d188598b433e2074f5" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 36457 } }
I20260812 06:19:29.716786 27012 raft_consensus.cc:385] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.716818 27012 raft_consensus.cc:740] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bb881748602c40d188598b433e2074f5, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.716935 27012 consensus_queue.cc:260] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [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: "bb881748602c40d188598b433e2074f5" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 36457 } }
I20260812 06:19:29.717000 27012 raft_consensus.cc:399] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.717036 27012 raft_consensus.cc:493] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.717082 27012 raft_consensus.cc:3060] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.717733 27012 raft_consensus.cc:515] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb881748602c40d188598b433e2074f5" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 36457 } }
I20260812 06:19:29.717846 27012 leader_election.cc:304] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [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: bb881748602c40d188598b433e2074f5; no voters: 
I20260812 06:19:29.718019 27012 leader_election.cc:290] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.718120 27019 raft_consensus.cc:2804] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.718327 27019 raft_consensus.cc:697] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 1 LEADER]: Becoming Leader. State: Replica: bb881748602c40d188598b433e2074f5, State: Running, Role: LEADER
I20260812 06:19:29.718380 27012 ts_tablet_manager.cc:1434] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:29.718397 26989 heartbeater.cc:499] Master 127.25.195.62:43373 was elected leader, sending a full tablet report...
I20260812 06:19:29.718540 27019 consensus_queue.cc:237] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [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: "bb881748602c40d188598b433e2074f5" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 36457 } }
I20260812 06:19:29.719756 26750 catalog_manager.cc:5719] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 reported cstate change: term changed from 0 to 1, leader changed from <none> to bb881748602c40d188598b433e2074f5 (127.25.195.1). New cstate: current_term: 1 leader_uuid: "bb881748602c40d188598b433e2074f5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb881748602c40d188598b433e2074f5" member_type: VOTER last_known_addr { host: "127.25.195.1" port: 36457 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:29.770231 26380 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.014s	sys 0.006s
I20260812 06:19:29.944550 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushMRSOp(bed8069140634f9f860c1fbe550c0b25): perf score=23.023690
I20260812 06:19:30.107239 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushMRSOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.162s	user 0.137s	sys 0.024s Metrics: {"bytes_written":15999665,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":150,"dirs.run_wall_time_us":692,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46583,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"update_count":1950}
I20260812 06:19:30.107811 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling LogGCOp(bed8069140634f9f860c1fbe550c0b25): free 20743880 bytes of WAL
I20260812 06:19:30.108038 26894 log_reader.cc:385] T bed8069140634f9f860c1fbe550c0b25: removed 2 log segments from log reader
I20260812 06:19:30.108136 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000001 (ops 1-6)
I20260812 06:19:30.108199 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000002 (ops 7-11)
I20260812 06:19:30.111985 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: LogGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:30.112262 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25): 20924067 bytes on disk
I20260812 06:19:30.112592 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.112938 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:30.127599 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.128014 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:30.284965 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.157s	user 0.121s	sys 0.036s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24446417,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":677,"lbm_read_time_us":12100,"lbm_reads_lt_1ms":550,"lbm_write_time_us":27378,"lbm_writes_lt_1ms":533,"mutex_wait_us":86,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":305,"threads_started":5,"update_count":2450}
I20260812 06:19:30.285528 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:30.327739 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.328141 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:30.337432 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.337867 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:30.490515 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.153s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":855,"lbm_read_time_us":8931,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26809,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:30.491035 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:30.542514 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.051s	user 0.015s	sys 0.032s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21559,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.543000 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:30.691013 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.148s	user 0.093s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754120,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":162,"lbm_read_time_us":10755,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22234,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.691497 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:30.733359 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.042s	user 0.018s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18327,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.733867 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:30.745239 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.745666 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:30.925452 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.180s	user 0.118s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":9658,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29320,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:30.925920 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:30.965121 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.039s	user 0.023s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17013,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.965608 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:30.975123 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.975585 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.115700 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.140s	user 0.098s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":9508,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27041,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:19:31.116160 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=11.118625
I20260812 06:19:31.144822 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.029s	user 0.012s	sys 0.014s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12427,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:31.145349 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:31.159974 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.160490 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.274474 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.114s	user 0.095s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754234,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":6952,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22500,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:31.275074 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=10.126437
I20260812 06:19:31.313642 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.038s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16634,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.314129 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:31.324884 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.325284 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushMRSOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.351549 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushMRSOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1161,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1528,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:31.352074 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling LogGCOp(bed8069140634f9f860c1fbe550c0b25): free 132571297 bytes of WAL
I20260812 06:19:31.352275 26894 log_reader.cc:385] T bed8069140634f9f860c1fbe550c0b25: removed 13 log segments from log reader
I20260812 06:19:31.352319 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000003 (ops 12-16)
I20260812 06:19:31.352344 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000004 (ops 17-20)
I20260812 06:19:31.352373 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000005 (ops 21-25)
I20260812 06:19:31.352404 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000006 (ops 26-30)
I20260812 06:19:31.352437 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000007 (ops 31-35)
I20260812 06:19:31.352458 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000008 (ops 36-40)
I20260812 06:19:31.352488 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000009 (ops 41-44)
I20260812 06:19:31.352520 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000010 (ops 45-49)
I20260812 06:19:31.352551 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000011 (ops 50-54)
I20260812 06:19:31.352582 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000012 (ops 55-59)
I20260812 06:19:31.352613 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000013 (ops 60-64)
I20260812 06:19:31.352644 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000014 (ops 65-69)
I20260812 06:19:31.352675 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000015 (ops 70-74)
I20260812 06:19:31.377864 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: LogGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:31.378185 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=3.181125
I20260812 06:19:31.390048 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4676999,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:19:31.390456 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25): 483 bytes on disk
I20260812 06:19:31.390832 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25) 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:19:31.391268 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:31.399482 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.008s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3054,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:19:31.399811 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.562592 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.163s	user 0.129s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28959289,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1657,"lbm_read_time_us":12889,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32042,"lbm_writes_lt_1ms":643,"mutex_wait_us":1259,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:19:31.563057 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:31.605924 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.043s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.606453 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:31.621126 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.621608 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.774003 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.152s	user 0.121s	sys 0.012s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":9943,"dirs.run_cpu_time_us":1022,"dirs.run_wall_time_us":6545,"lbm_read_time_us":9049,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26273,"lbm_writes_lt_1ms":543,"mutex_wait_us":3471,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:31.774716 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:31.817919 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.043s	user 0.015s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16402,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.818410 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:31.833016 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.833587 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:31.996352 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.163s	user 0.090s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":10349,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26356,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:31.996897 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:32.055754 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.059s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21628,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:32.056241 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:32.066057 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.066576 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:32.231241 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.165s	user 0.131s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":473,"lbm_read_time_us":11772,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27934,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:32.231778 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:32.289718 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.058s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20540,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.290274 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:32.299723 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.300169 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:32.467288 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.167s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856655,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":562,"lbm_read_time_us":11546,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25883,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.467784 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:32.518957 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.051s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17930,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.519479 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:32.529069 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.529518 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:32.698549 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.169s	user 0.109s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":88,"lbm_read_time_us":11523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26681,"lbm_writes_lt_1ms":543,"mutex_wait_us":16,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:32.699133 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:32.741669 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.042s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17704,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.742182 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:32.760600 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.761273 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushMRSOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:32.803586 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushMRSOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.042s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1316418,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":150,"dirs.run_wall_time_us":1094,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1532,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":7936}
I20260812 06:19:32.804284 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling LogGCOp(bed8069140634f9f860c1fbe550c0b25): free 133477472 bytes of WAL
I20260812 06:19:32.804515 26894 log_reader.cc:385] T bed8069140634f9f860c1fbe550c0b25: removed 13 log segments from log reader
I20260812 06:19:32.804563 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000016 (ops 75-79)
I20260812 06:19:32.804601 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000017 (ops 80-84)
I20260812 06:19:32.804636 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000018 (ops 85-89)
I20260812 06:19:32.804666 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000019 (ops 90-94)
I20260812 06:19:32.804697 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000020 (ops 95-99)
I20260812 06:19:32.804728 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000021 (ops 100-104)
I20260812 06:19:32.804759 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000022 (ops 105-109)
I20260812 06:19:32.804790 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000023 (ops 110-114)
I20260812 06:19:32.804822 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000024 (ops 115-119)
I20260812 06:19:32.804853 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000025 (ops 120-124)
I20260812 06:19:32.804884 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000026 (ops 125-129)
I20260812 06:19:32.804915 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000027 (ops 130-134)
I20260812 06:19:32.804945 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000028 (ops 135-139)
I20260812 06:19:32.831831 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: LogGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:32.832198 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25): 492 bytes on disk
I20260812 06:19:32.832629 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.833120 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=3.181125
I20260812 06:19:32.845177 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:19:32.845554 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:32.854318 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3393,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:32.854686 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:33.077605 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.223s	user 0.162s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061707,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":179,"lbm_read_time_us":14235,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37720,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":31488,"thread_start_us":69,"threads_started":1,"update_count":3500}
I20260812 06:19:33.078152 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=15.087375
I20260812 06:19:33.126766 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.048s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":21655,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:33.127158 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:33.137576 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:33.137951 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:33.296244 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.158s	user 0.086s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856643,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12953,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26403,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:19:33.296722 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=10.126437
I20260812 06:19:33.342764 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.046s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.343247 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:33.357275 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.357666 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:33.496527 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.139s	user 0.110s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754244,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":10320,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22212,"lbm_writes_lt_1ms":443,"mutex_wait_us":297,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:33.497080 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=10.126437
I20260812 06:19:33.534530 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15008,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.535020 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:33.545099 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.546178 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:33.665584 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.119s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":8668,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23254,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:33.666111 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=10.126437
I20260812 06:19:33.701244 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.035s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.701668 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:33.711591 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.712116 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:33.832376 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.120s	user 0.095s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1188,"lbm_read_time_us":8361,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24258,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:19:33.832931 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=10.126437
I20260812 06:19:33.879807 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.047s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17934,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.880322 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:33.894807 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.895241 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:34.038560 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.143s	user 0.093s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754241,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21319,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:34.039151 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=14.095187
I20260812 06:19:34.083938 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.045s	user 0.015s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18745,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.084363 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:34.093619 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.094112 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushMRSOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:34.128141 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushMRSOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.034s	user 0.023s	sys 0.007s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1080,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1263,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:34.128890 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling LogGCOp(bed8069140634f9f860c1fbe550c0b25): free 115943426 bytes of WAL
I20260812 06:19:34.129096 26894 log_reader.cc:385] T bed8069140634f9f860c1fbe550c0b25: removed 11 log segments from log reader
I20260812 06:19:34.129143 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000029 (ops 140-144)
I20260812 06:19:34.129181 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000030 (ops 145-149)
I20260812 06:19:34.129213 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000031 (ops 150-154)
I20260812 06:19:34.129245 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000032 (ops 155-159)
I20260812 06:19:34.129276 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000033 (ops 160-164)
I20260812 06:19:34.129307 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000034 (ops 165-169)
I20260812 06:19:34.129335 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000035 (ops 170-174)
I20260812 06:19:34.129365 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000036 (ops 175-179)
I20260812 06:19:34.129395 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000037 (ops 180-184)
I20260812 06:19:34.129424 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000038 (ops 185-189)
I20260812 06:19:34.129454 26894 log.cc:1079] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: Deleting log segment in path: /tmp/dist-test-taskMiHHDa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564572617-26380-0/minicluster-data/ts-0-root/wals/bed8069140634f9f860c1fbe550c0b25/wal-000000039 (ops 190-194)
I20260812 06:19:34.149310 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: LogGCOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:34.149677 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25): 447 bytes on disk
I20260812 06:19:34.150050 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: UndoDeltaBlockGCOp(bed8069140634f9f860c1fbe550c0b25) 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:19:34.150568 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25): perf score=2.188937
I20260812 06:19:34.162091 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: FlushDeltaMemStoresOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.162582 26993 maintenance_manager.cc:419] P bb881748602c40d188598b433e2074f5: Scheduling MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25): perf score=1.000000
I20260812 06:19:34.236826 26380 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.466s	user 1.673s	sys 0.129s
I20260812 06:19:34.315002 26380 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.002s	sys 0.000s
I20260812 06:19:34.315491 26380 tablet_server.cc:179] TabletServer@127.25.195.1:0 shutting down...
I20260812 06:19:34.336656 26894 maintenance_manager.cc:643] P bb881748602c40d188598b433e2074f5: MajorDeltaCompactionOp(bed8069140634f9f860c1fbe550c0b25) complete. Timing: real 0.174s	user 0.120s	sys 0.054s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959184,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":521,"lbm_read_time_us":13058,"lbm_reads_lt_1ms":665,"lbm_write_time_us":25551,"lbm_writes_lt_1ms":643,"mutex_wait_us":250,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":62,"threads_started":1,"update_count":3000}
I20260812 06:19:34.337541 26380 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:34.337762 26380 tablet_replica.cc:333] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5: stopping tablet replica
I20260812 06:19:34.337879 26380 raft_consensus.cc:2243] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.338029 26380 raft_consensus.cc:2272] T bed8069140634f9f860c1fbe550c0b25 P bb881748602c40d188598b433e2074f5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.355088 26380 tablet_server.cc:196] TabletServer@127.25.195.1:0 shutdown complete.
I20260812 06:19:34.386699 26380 master.cc:562] Master@127.25.195.62:43373 shutting down...
I20260812 06:19:34.389588 26380 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.389746 26380 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.389808 26380 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0771664c1f944b40adef636bd66f38b7: stopping tablet replica
I20260812 06:19:34.401788 26380 master.cc:584] Master@127.25.195.62:43373 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4868 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9891 ms total)

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