[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:45.773883 16080 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.180.62:40657
I20260812 06:17:45.774926 16080 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:45.775569 16080 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:45.782529 16080 server_base.cc:1061] running on GCE node
W20260812 06:17:45.782539 16094 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.782891 16095 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.783051 16099 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.783643 16080 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.783738 16080 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.783771 16080 hybrid_clock.cc:648] HybridClock initialized: now 1786515465783769 us; error 0 us; skew 500 ppm
I20260812 06:17:45.785598 16080 webserver.cc:533] Webserver started at http://127.15.180.62:39851/ using document root <none> and password file <none>
I20260812 06:17:45.786126 16080 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.786183 16080 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.786387 16080 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.788168 16080 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/master-0-root/instance:
uuid: "bec5689661d9488ab5a915c84396529d"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-x4qh"
I20260812 06:17:45.791720 16080 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:45.793859 16107 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.794900 16080 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:45.794999 16080 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/master-0-root
uuid: "bec5689661d9488ab5a915c84396529d"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-x4qh"
I20260812 06:17:45.795082 16080 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.809340 16080 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.809978 16080 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:45.810118 16080 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.818054 16080 rpc_server.cc:307] RPC server started. Bound to: 127.15.180.62:40657
I20260812 06:17:45.818068 16208 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.180.62:40657 every 8 connection(s)
I20260812 06:17:45.820444 16210 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.825791 16210 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: Bootstrap starting.
I20260812 06:17:45.828143 16210 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.829052 16210 log.cc:826] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:45.830760 16210 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: No bootstrap required, opened a new log
I20260812 06:17:45.833531 16210 raft_consensus.cc:359] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bec5689661d9488ab5a915c84396529d" member_type: VOTER }
I20260812 06:17:45.833695 16210 raft_consensus.cc:385] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.833829 16210 raft_consensus.cc:740] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bec5689661d9488ab5a915c84396529d, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.834439 16210 consensus_queue.cc:260] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [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: "bec5689661d9488ab5a915c84396529d" member_type: VOTER }
I20260812 06:17:45.834602 16210 raft_consensus.cc:399] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.834695 16210 raft_consensus.cc:493] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.834849 16210 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.835785 16210 raft_consensus.cc:515] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bec5689661d9488ab5a915c84396529d" member_type: VOTER }
I20260812 06:17:45.836225 16210 leader_election.cc:304] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [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: bec5689661d9488ab5a915c84396529d; no voters: 
I20260812 06:17:45.836555 16210 leader_election.cc:290] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.836691 16216 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.836966 16216 raft_consensus.cc:697] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 1 LEADER]: Becoming Leader. State: Replica: bec5689661d9488ab5a915c84396529d, State: Running, Role: LEADER
I20260812 06:17:45.837440 16216 consensus_queue.cc:237] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [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: "bec5689661d9488ab5a915c84396529d" member_type: VOTER }
I20260812 06:17:45.837551 16210 sys_catalog.cc:565] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:45.839383 16219 sys_catalog.cc:455] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [sys.catalog]: SysCatalogTable state changed. Reason: New leader bec5689661d9488ab5a915c84396529d. Latest consensus state: current_term: 1 leader_uuid: "bec5689661d9488ab5a915c84396529d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bec5689661d9488ab5a915c84396529d" member_type: VOTER } }
I20260812 06:17:45.839457 16218 sys_catalog.cc:455] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bec5689661d9488ab5a915c84396529d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bec5689661d9488ab5a915c84396529d" member_type: VOTER } }
I20260812 06:17:45.839506 16219 sys_catalog.cc:458] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.839565 16218 sys_catalog.cc:458] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.839892 16233 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:45.842502 16233 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:45.842757 16080 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:45.847319 16233 catalog_manager.cc:1383] Generated new cluster ID: 401491c14b4b40f9a120768f725d535b
I20260812 06:17:45.847395 16233 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:45.860805 16233 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:45.861959 16233 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:45.876837 16233 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: Generated new TSK 0
I20260812 06:17:45.877696 16233 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:45.908058 16080 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:45.911700 16251 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.911711 16250 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.911832 16080 server_base.cc:1061] running on GCE node
W20260812 06:17:45.911693 16254 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.912187 16080 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.912236 16080 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.912252 16080 hybrid_clock.cc:648] HybridClock initialized: now 1786515465912252 us; error 0 us; skew 500 ppm
I20260812 06:17:45.913295 16080 webserver.cc:533] Webserver started at http://127.15.180.1:43439/ using document root <none> and password file <none>
I20260812 06:17:45.913514 16080 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.913569 16080 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.913682 16080 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.914124 16080 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/instance:
uuid: "9e4131d0139f41489fa96b57920aa2b7"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-x4qh"
I20260812 06:17:45.915755 16080 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:45.916906 16263 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.917156 16080 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:45.917230 16080 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root
uuid: "9e4131d0139f41489fa96b57920aa2b7"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-x4qh"
I20260812 06:17:45.917320 16080 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.928499 16080 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.928959 16080 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.929467 16080 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:45.930361 16080 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:45.930411 16080 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.930480 16080 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:45.930521 16080 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.937829 16080 rpc_server.cc:307] RPC server started. Bound to: 127.15.180.1:36709
I20260812 06:17:45.937844 16390 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.180.1:36709 every 8 connection(s)
I20260812 06:17:45.950958 16391 heartbeater.cc:344] Connected to a master server at 127.15.180.62:40657
I20260812 06:17:45.951211 16391 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:45.951694 16391 heartbeater.cc:507] Master 127.15.180.62:40657 requested a full tablet report, sending...
I20260812 06:17:45.953234 16148 ts_manager.cc:194] Registered new tserver with Master: 9e4131d0139f41489fa96b57920aa2b7 (127.15.180.1:36709)
I20260812 06:17:45.953361 16080 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014860639s
I20260812 06:17:45.954730 16148 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45572
I20260812 06:17:45.963097 16148 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45576:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:45.977936 16322 tablet_service.cc:1511] Processing CreateTablet for tablet 85c9d6353b114716b79651e85fbdd2b8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9be9743a15d545f38a957b3ea87c9c4c]), partition=
I20260812 06:17:45.978422 16322 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 85c9d6353b114716b79651e85fbdd2b8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.981725 16418 tablet_bootstrap.cc:492] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Bootstrap starting.
I20260812 06:17:45.982692 16418 tablet_bootstrap.cc:654] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.983887 16418 tablet_bootstrap.cc:492] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: No bootstrap required, opened a new log
I20260812 06:17:45.984011 16418 ts_tablet_manager.cc:1403] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:45.984477 16418 raft_consensus.cc:359] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e4131d0139f41489fa96b57920aa2b7" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 36709 } }
I20260812 06:17:45.984598 16418 raft_consensus.cc:385] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.984645 16418 raft_consensus.cc:740] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9e4131d0139f41489fa96b57920aa2b7, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.984787 16418 consensus_queue.cc:260] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [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: "9e4131d0139f41489fa96b57920aa2b7" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 36709 } }
I20260812 06:17:45.984906 16418 raft_consensus.cc:399] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.984956 16418 raft_consensus.cc:493] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.985009 16418 raft_consensus.cc:3060] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.985940 16418 raft_consensus.cc:515] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e4131d0139f41489fa96b57920aa2b7" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 36709 } }
I20260812 06:17:45.986090 16418 leader_election.cc:304] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [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: 9e4131d0139f41489fa96b57920aa2b7; no voters: 
I20260812 06:17:45.986332 16418 leader_election.cc:290] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.986438 16423 raft_consensus.cc:2804] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.986641 16423 raft_consensus.cc:697] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 1 LEADER]: Becoming Leader. State: Replica: 9e4131d0139f41489fa96b57920aa2b7, State: Running, Role: LEADER
I20260812 06:17:45.986737 16418 ts_tablet_manager.cc:1434] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:45.987037 16391 heartbeater.cc:499] Master 127.15.180.62:40657 was elected leader, sending a full tablet report...
I20260812 06:17:45.986843 16423 consensus_queue.cc:237] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [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: "9e4131d0139f41489fa96b57920aa2b7" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 36709 } }
I20260812 06:17:45.990178 16148 catalog_manager.cc:5719] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9e4131d0139f41489fa96b57920aa2b7 (127.15.180.1). New cstate: current_term: 1 leader_uuid: "9e4131d0139f41489fa96b57920aa2b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e4131d0139f41489fa96b57920aa2b7" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 36709 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:46.054948 16080 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.019s	sys 0.008s
I20260812 06:17:46.189167 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8): perf score=19.054940
I20260812 06:17:46.356117 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.167s	user 0.132s	sys 0.028s Metrics: {"bytes_written":12307493,"cfile_init":1,"compiler_manager_pool.queue_time_us":217,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":978,"drs_written":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41601,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":145,"threads_started":1,"update_count":1500}
I20260812 06:17:46.357203 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling LogGCOp(85c9d6353b114716b79651e85fbdd2b8): free 20743880 bytes of WAL
I20260812 06:17:46.357515 16271 log_reader.cc:385] T 85c9d6353b114716b79651e85fbdd2b8: removed 2 log segments from log reader
I20260812 06:17:46.357578 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000001 (ops 1-6)
I20260812 06:17:46.357628 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000002 (ops 7-11)
I20260812 06:17:46.363125 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: LogGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:46.363569 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8): 16411396 bytes on disk
I20260812 06:17:46.364161 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:46.364593 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:46.380769 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.381304 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:46.542623 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.161s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":9323,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24551,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":462,"threads_started":5,"update_count":2000}
I20260812 06:17:46.543222 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:46.576768 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.033s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.577303 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:46.588274 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.588939 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:46.711928 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.123s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":7954,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25111,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:17:46.712445 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:46.752753 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.040s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15043,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.753227 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:46.763536 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.764225 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:46.883729 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.119s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1133,"lbm_read_time_us":8985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22168,"lbm_writes_lt_1ms":443,"mutex_wait_us":397,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:46.884420 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:46.931116 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.046s	user 0.025s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16442,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.931757 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:46.942903 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.943320 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:47.087191 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.144s	user 0.102s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":11219,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23158,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:17:47.087792 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:47.132347 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.044s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16449,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.132805 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:47.144414 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.145076 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:47.265606 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.120s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":8055,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25363,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.266062 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:47.315945 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.050s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17744,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.316385 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:47.327893 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.328648 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:47.447942 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.119s	user 0.090s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22361,"lbm_writes_lt_1ms":443,"mutex_wait_us":123,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:47.448853 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=10.126437
I20260812 06:17:47.493767 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.045s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15332,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.494403 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:47.505241 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.505810 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:47.548029 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.042s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1368,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1520,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:47.548844 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling LogGCOp(85c9d6353b114716b79651e85fbdd2b8): free 112239259 bytes of WAL
I20260812 06:17:47.549078 16271 log_reader.cc:385] T 85c9d6353b114716b79651e85fbdd2b8: removed 11 log segments from log reader
I20260812 06:17:47.549125 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000003 (ops 12-16)
I20260812 06:17:47.549153 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000004 (ops 17-21)
I20260812 06:17:47.549213 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000005 (ops 22-26)
I20260812 06:17:47.549252 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000006 (ops 27-31)
I20260812 06:17:47.549292 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000007 (ops 32-36)
I20260812 06:17:47.549365 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000008 (ops 37-41)
I20260812 06:17:47.549404 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000009 (ops 42-46)
I20260812 06:17:47.549443 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000010 (ops 47-50)
I20260812 06:17:47.549479 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000011 (ops 51-55)
I20260812 06:17:47.549517 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000012 (ops 56-60)
I20260812 06:17:47.549556 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000013 (ops 61-65)
I20260812 06:17:47.575204 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: LogGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.026s	user 0.004s	sys 0.019s Metrics: {}
I20260812 06:17:47.575657 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=3.181125
I20260812 06:17:47.594278 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.018s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4566,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:47.594715 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8): 448 bytes on disk
I20260812 06:17:47.595150 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.595642 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:47.605057 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3545,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:47.605522 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:47.809618 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.204s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1066,"lbm_read_time_us":12298,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35699,"lbm_writes_lt_1ms":643,"mutex_wait_us":90,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:17:47.810272 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:47.882105 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.072s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24707,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.882665 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:47.893222 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.893895 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:48.079357 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.185s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":968,"lbm_read_time_us":12930,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31207,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:48.080008 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:48.136998 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.057s	user 0.011s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20328,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.137535 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.148710 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.149160 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:48.322758 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.173s	user 0.123s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":14939,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28541,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:48.323529 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:48.386891 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.063s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25972,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.387528 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.398326 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.398856 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:48.574749 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.176s	user 0.110s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":13090,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31124,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:48.575402 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=11.118625
I20260812 06:17:48.620659 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.045s	user 0.011s	sys 0.033s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20098,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.621315 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.658103 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.037s	user 0.008s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5365,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.658728 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.670781 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.671402 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:48.854393 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.183s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":992,"lbm_read_time_us":13459,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30104,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:48.854957 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=11.118625
I20260812 06:17:48.899206 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18574,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.899816 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.919665 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5721,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.920118 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:48.930220 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.930649 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:49.102190 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.171s	user 0.110s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":239,"lbm_read_time_us":10720,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27875,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:17:49.102804 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:49.154505 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.051s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20627,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.155125 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:49.171299 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.172066 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:49.216296 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.044s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1559,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1881,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:49.217394 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8): 507 bytes on disk
I20260812 06:17:49.217932 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:49.218529 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=3.181125
I20260812 06:17:49.232539 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4790,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:49.233062 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling LogGCOp(85c9d6353b114716b79651e85fbdd2b8): free 141338451 bytes of WAL
I20260812 06:17:49.233340 16271 log_reader.cc:385] T 85c9d6353b114716b79651e85fbdd2b8: removed 14 log segments from log reader
I20260812 06:17:49.233402 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000014 (ops 66-70)
I20260812 06:17:49.233443 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000015 (ops 71-74)
I20260812 06:17:49.233474 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000016 (ops 75-79)
I20260812 06:17:49.233503 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000017 (ops 80-84)
I20260812 06:17:49.233532 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000018 (ops 85-89)
I20260812 06:17:49.233568 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000019 (ops 90-94)
I20260812 06:17:49.233601 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000020 (ops 95-99)
I20260812 06:17:49.233628 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000021 (ops 100-104)
I20260812 06:17:49.233654 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000022 (ops 105-109)
I20260812 06:17:49.233682 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000023 (ops 110-114)
I20260812 06:17:49.233711 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000024 (ops 115-119)
I20260812 06:17:49.233745 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000025 (ops 120-124)
I20260812 06:17:49.233775 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000026 (ops 125-128)
I20260812 06:17:49.233801 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000027 (ops 129-133)
I20260812 06:17:49.269912 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: LogGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.037s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:49.270305 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:49.294292 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.024s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.294732 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:49.305160 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.305611 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:49.557075 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.251s	user 0.187s	sys 0.064s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":450,"lbm_read_time_us":17479,"lbm_reads_lt_1ms":875,"lbm_write_time_us":45911,"lbm_writes_lt_1ms":843,"mutex_wait_us":46,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:17:49.557792 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=18.063937
I20260812 06:17:49.620218 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.062s	user 0.033s	sys 0.028s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":27696,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:49.621076 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:49.637755 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.638237 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:49.807181 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.169s	user 0.128s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":988,"lbm_read_time_us":11752,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33711,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:49.807855 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:49.868498 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.060s	user 0.043s	sys 0.014s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":27747,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.869120 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=3.181125
I20260812 06:17:49.886652 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.017s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:49.887118 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:49.896636 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3461,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.897104 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.068064 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.171s	user 0.143s	sys 0.023s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":923,"lbm_read_time_us":12519,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33199,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3000}
I20260812 06:17:50.068655 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:50.113938 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.114578 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:50.125619 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.126123 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.283892 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.158s	user 0.136s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":11823,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29044,"lbm_writes_lt_1ms":543,"mutex_wait_us":117,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:50.285162 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=12.110812
I20260812 06:17:50.329257 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.044s	user 0.026s	sys 0.016s Metrics: {"bytes_written":13620265,"delete_count":0,"lbm_write_time_us":19100,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:17:50.329845 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.196750
I20260812 06:17:50.352243 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.022s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3593,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:50.352767 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:50.363279 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.363741 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.525772 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.162s	user 0.102s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1020,"lbm_read_time_us":12601,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29310,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:50.526477 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:50.586781 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.060s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.587344 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:50.602406 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.602975 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.635790 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushMRSOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":166,"dirs.run_wall_time_us":1339,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1352,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:50.636428 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling LogGCOp(85c9d6353b114716b79651e85fbdd2b8): free 112239561 bytes of WAL
I20260812 06:17:50.636641 16271 log_reader.cc:385] T 85c9d6353b114716b79651e85fbdd2b8: removed 11 log segments from log reader
I20260812 06:17:50.636700 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000028 (ops 134-138)
I20260812 06:17:50.636754 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000029 (ops 139-143)
I20260812 06:17:50.636811 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000030 (ops 144-148)
I20260812 06:17:50.636858 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000031 (ops 149-153)
I20260812 06:17:50.636897 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000032 (ops 154-158)
I20260812 06:17:50.636933 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000033 (ops 159-163)
I20260812 06:17:50.636971 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000034 (ops 164-168)
I20260812 06:17:50.637020 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000035 (ops 169-172)
I20260812 06:17:50.637055 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000036 (ops 173-177)
I20260812 06:17:50.637090 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000037 (ops 178-182)
I20260812 06:17:50.637125 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000038 (ops 183-187)
I20260812 06:17:50.662374 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: LogGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:50.662854 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=3.181125
I20260812 06:17:50.677054 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:50.677475 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling LogGCOp(85c9d6353b114716b79651e85fbdd2b8): free 12018004 bytes of WAL
I20260812 06:17:50.677678 16271 log_reader.cc:385] T 85c9d6353b114716b79651e85fbdd2b8: removed 1 log segments from log reader
I20260812 06:17:50.677744 16271 log.cc:1079] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/85c9d6353b114716b79651e85fbdd2b8/wal-000000039 (ops 188-192)
I20260812 06:17:50.680145 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: LogGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:50.680434 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=2.188937
I20260812 06:17:50.689584 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.690188 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8): 463 bytes on disk
I20260812 06:17:50.690793 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: UndoDeltaBlockGCOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.691604 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.874687 16080 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.820s	user 1.760s	sys 0.179s
I20260812 06:17:50.896639 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.205s	user 0.118s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15700,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39041,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3500}
I20260812 06:17:50.897135 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8): perf score=14.095187
I20260812 06:17:50.929576 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: FlushDeltaMemStoresOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.032s	user 0.024s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15583,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.930037 16393 maintenance_manager.cc:419] P 9e4131d0139f41489fa96b57920aa2b7: Scheduling MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8): perf score=1.000000
I20260812 06:17:50.948559 16080 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.002s	sys 0.000s
I20260812 06:17:50.949210 16080 tablet_server.cc:179] TabletServer@127.15.180.1:0 shutting down...
I20260812 06:17:51.047781 16271 maintenance_manager.cc:643] P 9e4131d0139f41489fa96b57920aa2b7: MajorDeltaCompactionOp(85c9d6353b114716b79651e85fbdd2b8) complete. Timing: real 0.118s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":494,"lbm_read_time_us":8764,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24597,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:17:51.050179 16080 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:51.050745 16080 tablet_replica.cc:333] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7: stopping tablet replica
I20260812 06:17:51.051031 16080 raft_consensus.cc:2243] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.051394 16080 raft_consensus.cc:2272] T 85c9d6353b114716b79651e85fbdd2b8 P 9e4131d0139f41489fa96b57920aa2b7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.067978 16080 tablet_server.cc:196] TabletServer@127.15.180.1:0 shutdown complete.
I20260812 06:17:51.091470 16080 master.cc:562] Master@127.15.180.62:40657 shutting down...
I20260812 06:17:51.095780 16080 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.096011 16080 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.096101 16080 tablet_replica.cc:333] T 00000000000000000000000000000000 P bec5689661d9488ab5a915c84396529d: stopping tablet replica
I20260812 06:17:51.108739 16080 master.cc:584] Master@127.15.180.62:40657 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5426 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:51.213333 16080 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.180.62:42061
I20260812 06:17:51.213774 16080 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.216182 16450 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:51.216271 16080 server_base.cc:1061] running on GCE node
W20260812 06:17:51.216288 16454 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.216441 16460 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:51.216652 16080 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.216729 16080 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:51.216758 16080 hybrid_clock.cc:648] HybridClock initialized: now 1786515471216758 us; error 0 us; skew 500 ppm
I20260812 06:17:51.217758 16080 webserver.cc:533] Webserver started at http://127.15.180.62:39061/ using document root <none> and password file <none>
I20260812 06:17:51.217959 16080 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.218045 16080 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.218146 16080 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.218596 16080 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/master-0-root/instance:
uuid: "de9ac6697a39432faf351395ea7bffb0"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-x4qh"
I20260812 06:17:51.220362 16080 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:51.221457 16473 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.221756 16080 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:51.221858 16080 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/master-0-root
uuid: "de9ac6697a39432faf351395ea7bffb0"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-x4qh"
I20260812 06:17:51.221953 16080 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:51.227247 16080 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.227617 16080 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.231760 16080 rpc_server.cc:307] RPC server started. Bound to: 127.15.180.62:42061
I20260812 06:17:51.232992 16566 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.180.62:42061 every 8 connection(s)
I20260812 06:17:51.238408 16569 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:51.240202 16569 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0: Bootstrap starting.
I20260812 06:17:51.240917 16569 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.241859 16569 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0: No bootstrap required, opened a new log
I20260812 06:17:51.242202 16569 raft_consensus.cc:359] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER }
I20260812 06:17:51.242281 16569 raft_consensus.cc:385] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.242303 16569 raft_consensus.cc:740] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: de9ac6697a39432faf351395ea7bffb0, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.242413 16569 consensus_queue.cc:260] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [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: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER }
I20260812 06:17:51.242471 16569 raft_consensus.cc:399] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.242493 16569 raft_consensus.cc:493] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.242522 16569 raft_consensus.cc:3060] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.243144 16569 raft_consensus.cc:515] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER }
I20260812 06:17:51.243253 16569 leader_election.cc:304] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [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: de9ac6697a39432faf351395ea7bffb0; no voters: 
I20260812 06:17:51.243476 16569 leader_election.cc:290] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.243588 16573 raft_consensus.cc:2804] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.243801 16573 raft_consensus.cc:697] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 1 LEADER]: Becoming Leader. State: Replica: de9ac6697a39432faf351395ea7bffb0, State: Running, Role: LEADER
I20260812 06:17:51.243948 16573 consensus_queue.cc:237] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [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: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER }
I20260812 06:17:51.244002 16569 sys_catalog.cc:565] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:51.244423 16574 sys_catalog.cc:455] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "de9ac6697a39432faf351395ea7bffb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER } }
I20260812 06:17:51.244460 16577 sys_catalog.cc:455] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader de9ac6697a39432faf351395ea7bffb0. Latest consensus state: current_term: 1 leader_uuid: "de9ac6697a39432faf351395ea7bffb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de9ac6697a39432faf351395ea7bffb0" member_type: VOTER } }
I20260812 06:17:51.244519 16574 sys_catalog.cc:458] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.244567 16577 sys_catalog.cc:458] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.244830 16580 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:51.245618 16580 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:51.245994 16080 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:51.247470 16580 catalog_manager.cc:1383] Generated new cluster ID: 956e35c2f18d4fa2bdc9250629f35120
I20260812 06:17:51.247537 16580 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:51.278559 16580 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:51.279141 16580 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:51.284008 16580 catalog_manager.cc:6092] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0: Generated new TSK 0
I20260812 06:17:51.284186 16580 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:51.310717 16080 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.312903 16605 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.313033 16604 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.313052 16608 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:51.313071 16080 server_base.cc:1061] running on GCE node
I20260812 06:17:51.313493 16080 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.313534 16080 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:51.313549 16080 hybrid_clock.cc:648] HybridClock initialized: now 1786515471313550 us; error 0 us; skew 500 ppm
I20260812 06:17:51.314378 16080 webserver.cc:533] Webserver started at http://127.15.180.1:41057/ using document root <none> and password file <none>
I20260812 06:17:51.314558 16080 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.314625 16080 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.314709 16080 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.315135 16080 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/instance:
uuid: "8a6cb6704f5d4e55aae7921395e1b384"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-x4qh"
I20260812 06:17:51.316694 16080 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:51.317610 16616 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.317878 16080 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:51.317955 16080 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root
uuid: "8a6cb6704f5d4e55aae7921395e1b384"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-x4qh"
I20260812 06:17:51.318014 16080 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:51.321764 16080 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.322063 16080 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.322288 16080 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:51.322748 16080 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:51.322786 16080 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.322850 16080 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:51.322888 16080 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.327225 16080 rpc_server.cc:307] RPC server started. Bound to: 127.15.180.1:39633
I20260812 06:17:51.327247 16735 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.180.1:39633 every 8 connection(s)
I20260812 06:17:51.332209 16736 heartbeater.cc:344] Connected to a master server at 127.15.180.62:42061
I20260812 06:17:51.332346 16736 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:51.332612 16736 heartbeater.cc:507] Master 127.15.180.62:42061 requested a full tablet report, sending...
I20260812 06:17:51.333461 16494 ts_manager.cc:194] Registered new tserver with Master: 8a6cb6704f5d4e55aae7921395e1b384 (127.15.180.1:39633)
I20260812 06:17:51.334184 16494 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60320
I20260812 06:17:51.334326 16080 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006630439s
I20260812 06:17:51.341140 16494 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60336:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:51.351095 16668 tablet_service.cc:1511] Processing CreateTablet for tablet b56ef96b9fe146e288e5c60c309b931b (DEFAULT_TABLE table=heavy-update-compaction-test [id=77d7dfbb06bb4af1a226fe933abeefa5]), partition=
I20260812 06:17:51.351334 16668 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b56ef96b9fe146e288e5c60c309b931b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:51.353516 16758 tablet_bootstrap.cc:492] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Bootstrap starting.
I20260812 06:17:51.354388 16758 tablet_bootstrap.cc:654] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.355633 16758 tablet_bootstrap.cc:492] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: No bootstrap required, opened a new log
I20260812 06:17:51.355729 16758 ts_tablet_manager.cc:1403] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:51.356166 16758 raft_consensus.cc:359] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a6cb6704f5d4e55aae7921395e1b384" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 39633 } }
I20260812 06:17:51.356254 16758 raft_consensus.cc:385] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.356315 16758 raft_consensus.cc:740] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8a6cb6704f5d4e55aae7921395e1b384, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.356469 16758 consensus_queue.cc:260] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [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: "8a6cb6704f5d4e55aae7921395e1b384" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 39633 } }
I20260812 06:17:51.356541 16758 raft_consensus.cc:399] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.356595 16758 raft_consensus.cc:493] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.356653 16758 raft_consensus.cc:3060] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.357429 16758 raft_consensus.cc:515] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a6cb6704f5d4e55aae7921395e1b384" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 39633 } }
I20260812 06:17:51.357601 16758 leader_election.cc:304] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [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: 8a6cb6704f5d4e55aae7921395e1b384; no voters: 
I20260812 06:17:51.357847 16758 leader_election.cc:290] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.357985 16760 raft_consensus.cc:2804] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.358207 16758 ts_tablet_manager.cc:1434] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:51.358229 16760 raft_consensus.cc:697] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 1 LEADER]: Becoming Leader. State: Replica: 8a6cb6704f5d4e55aae7921395e1b384, State: Running, Role: LEADER
I20260812 06:17:51.358397 16736 heartbeater.cc:499] Master 127.15.180.62:42061 was elected leader, sending a full tablet report...
I20260812 06:17:51.358376 16760 consensus_queue.cc:237] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [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: "8a6cb6704f5d4e55aae7921395e1b384" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 39633 } }
I20260812 06:17:51.359773 16494 catalog_manager.cc:5719] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8a6cb6704f5d4e55aae7921395e1b384 (127.15.180.1). New cstate: current_term: 1 leader_uuid: "8a6cb6704f5d4e55aae7921395e1b384" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a6cb6704f5d4e55aae7921395e1b384" member_type: VOTER last_known_addr { host: "127.15.180.1" port: 39633 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:51.418712 16080 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.012s	sys 0.010s
I20260812 06:17:51.578127 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b): perf score=19.054940
I20260812 06:17:51.731280 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.153s	user 0.100s	sys 0.048s Metrics: {"bytes_written":13989481,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":956,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40515,"lbm_writes_lt_1ms":798,"mutex_wait_us":820,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":9600,"update_count":1705}
I20260812 06:17:51.732069 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.196750
I20260812 06:17:51.749922 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.018s	user 0.003s	sys 0.010s Metrics: {"bytes_written":3282163,"delete_count":0,"lbm_write_time_us":3163,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:51.750351 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling LogGCOp(b56ef96b9fe146e288e5c60c309b931b): free 20743831 bytes of WAL
I20260812 06:17:51.750554 16623 log_reader.cc:385] T b56ef96b9fe146e288e5c60c309b931b: removed 2 log segments from log reader
I20260812 06:17:51.750617 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000001 (ops 1-6)
I20260812 06:17:51.750682 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000002 (ops 7-11)
I20260812 06:17:51.755041 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: LogGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:51.755347 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b): 16411398 bytes on disk
I20260812 06:17:51.755775 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.756153 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:51.765859 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":3468,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:51.766453 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:51.957158 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.190s	user 0.095s	sys 0.084s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774774,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":602,"lbm_read_time_us":12311,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29129,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25984,"thread_start_us":341,"threads_started":5,"update_count":2500}
I20260812 06:17:51.957793 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:52.024628 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.067s	user 0.025s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25823,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.025134 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:52.040290 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.040853 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:52.205374 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.164s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":417,"lbm_read_time_us":11880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27504,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:52.206027 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:52.258587 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.052s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23225,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.259064 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:52.269529 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.269936 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:52.444849 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.175s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":12843,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29688,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:52.445443 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:52.508137 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.063s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19943,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:52.508765 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:52.525632 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.526190 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:52.718294 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.192s	user 0.130s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":13957,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31447,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:17:52.718900 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:52.776037 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.057s	user 0.014s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22369,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.776485 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:52.798012 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.798614 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:52.980289 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.181s	user 0.130s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":972,"lbm_read_time_us":12473,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28078,"lbm_writes_lt_1ms":543,"mutex_wait_us":413,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:17:52.982300 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:53.033037 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.050s	user 0.041s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22609,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.033684 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:53.046449 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.046986 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:53.080773 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1281,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1621,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:53.081355 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling LogGCOp(b56ef96b9fe146e288e5c60c309b931b): free 120553389 bytes of WAL
I20260812 06:17:53.081586 16623 log_reader.cc:385] T b56ef96b9fe146e288e5c60c309b931b: removed 12 log segments from log reader
I20260812 06:17:53.081630 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000003 (ops 12-16)
I20260812 06:17:53.081688 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000004 (ops 17-21)
I20260812 06:17:53.081733 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000005 (ops 22-26)
I20260812 06:17:53.081761 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000006 (ops 27-31)
I20260812 06:17:53.081801 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000007 (ops 32-36)
I20260812 06:17:53.081830 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000008 (ops 37-40)
I20260812 06:17:53.081869 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000009 (ops 41-45)
I20260812 06:17:53.081909 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000010 (ops 46-50)
I20260812 06:17:53.081950 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000011 (ops 51-54)
I20260812 06:17:53.081990 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000012 (ops 55-59)
I20260812 06:17:53.082028 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000013 (ops 60-64)
I20260812 06:17:53.082068 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000014 (ops 65-69)
I20260812 06:17:53.110116 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: LogGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:53.110558 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b): 472 bytes on disk
I20260812 06:17:53.111022 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.111709 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=3.181125
I20260812 06:17:53.128216 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.016s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:53.128794 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:53.142581 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5313,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.143167 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:53.398188 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.255s	user 0.144s	sys 0.102s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1034,"lbm_read_time_us":17268,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42338,"lbm_writes_lt_1ms":743,"mutex_wait_us":107,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:17:53.398973 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=18.063937
I20260812 06:17:53.469925 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.071s	user 0.049s	sys 0.007s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26825,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:53.470407 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:53.481431 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.481875 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:53.693392 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.211s	user 0.120s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":13415,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33566,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":3000}
I20260812 06:17:53.694087 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=18.063937
I20260812 06:17:53.764514 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.070s	user 0.039s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25537,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:53.764976 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:53.776665 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.777166 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:53.985462 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.208s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":14356,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34863,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:17:53.986073 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=15.087375
I20260812 06:17:54.026108 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":18166,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:54.026568 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.036388 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3573,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.036860 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:54.230337 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.193s	user 0.105s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1005,"lbm_read_time_us":13928,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31973,"lbm_writes_lt_1ms":543,"mutex_wait_us":400,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:54.230908 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:54.290021 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.059s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19024,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.290570 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.302217 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.303490 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:54.479523 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.176s	user 0.123s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":893,"lbm_read_time_us":11471,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29203,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:54.480050 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:54.542196 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.062s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24265,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.542845 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.553542 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.554013 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:54.593142 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.039s	user 0.021s	sys 0.008s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":332,"dirs.run_wall_time_us":1538,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1469,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:54.594025 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling LogGCOp(b56ef96b9fe146e288e5c60c309b931b): free 120553380 bytes of WAL
I20260812 06:17:54.594309 16623 log_reader.cc:385] T b56ef96b9fe146e288e5c60c309b931b: removed 12 log segments from log reader
I20260812 06:17:54.594674 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000015 (ops 70-74)
I20260812 06:17:54.594756 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000016 (ops 75-78)
I20260812 06:17:54.594795 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000017 (ops 79-83)
I20260812 06:17:54.594818 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000018 (ops 84-88)
I20260812 06:17:54.594842 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000019 (ops 89-93)
I20260812 06:17:54.594908 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000020 (ops 94-98)
I20260812 06:17:54.594971 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000021 (ops 99-103)
I20260812 06:17:54.595021 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000022 (ops 104-108)
I20260812 06:17:54.595054 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000023 (ops 109-113)
I20260812 06:17:54.595078 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000024 (ops 114-118)
I20260812 06:17:54.595100 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000025 (ops 119-122)
I20260812 06:17:54.595124 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000026 (ops 123-127)
I20260812 06:17:54.623219 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: LogGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:54.623764 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.639853 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.016s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4225736,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:17:54.640276 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.650660 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:54.651168 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:54.875865 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.224s	user 0.156s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979754,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":494,"dirs.run_cpu_time_us":1122,"dirs.run_wall_time_us":7175,"lbm_read_time_us":16423,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38521,"lbm_writes_lt_1ms":743,"mutex_wait_us":118,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":46976,"update_count":3500}
I20260812 06:17:54.876557 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=18.063937
I20260812 06:17:54.942922 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.066s	user 0.033s	sys 0.030s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29724,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:54.943487 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:54.956382 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.956874 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b): 462 bytes on disk
I20260812 06:17:54.957368 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.957895 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:55.123358 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.165s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":769,"lbm_read_time_us":12985,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32056,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:17:55.124166 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:55.180931 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.057s	user 0.019s	sys 0.036s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26902,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.181638 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:55.208076 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.026s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.208532 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:55.219725 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.220188 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:55.394627 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.174s	user 0.136s	sys 0.037s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":537,"lbm_read_time_us":11784,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38577,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":3000}
I20260812 06:17:55.395903 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:55.448807 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.053s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.449321 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:55.460529 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.461176 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:55.634764 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.173s	user 0.097s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":441,"lbm_read_time_us":9388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32788,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:17:55.635636 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:55.691833 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.056s	user 0.017s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24065,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.692497 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:55.837535 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.145s	user 0.089s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":295,"lbm_read_time_us":9581,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23751,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:17:55.838162 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=14.095187
I20260812 06:17:55.896654 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.058s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20878,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.897233 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:55.908187 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.908690 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:55.951941 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushMRSOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.043s	user 0.033s	sys 0.002s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1269,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1358,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":2816}
I20260812 06:17:55.952662 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling LogGCOp(b56ef96b9fe146e288e5c60c309b931b): free 112239608 bytes of WAL
I20260812 06:17:55.952926 16623 log_reader.cc:385] T b56ef96b9fe146e288e5c60c309b931b: removed 11 log segments from log reader
I20260812 06:17:55.952973 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000027 (ops 128-132)
I20260812 06:17:55.953002 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000028 (ops 133-137)
I20260812 06:17:55.953087 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000029 (ops 138-142)
I20260812 06:17:55.953137 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000030 (ops 143-147)
I20260812 06:17:55.953204 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000031 (ops 148-152)
I20260812 06:17:55.953243 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000032 (ops 153-156)
I20260812 06:17:55.953289 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000033 (ops 157-161)
I20260812 06:17:55.953330 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000034 (ops 162-166)
I20260812 06:17:55.953369 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000035 (ops 167-171)
I20260812 06:17:55.953409 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000036 (ops 172-176)
I20260812 06:17:55.953449 16623 log.cc:1079] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: Deleting log segment in path: /tmp/dist-test-taskk9krP5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465763084-16080-0/minicluster-data/ts-0-root/wals/b56ef96b9fe146e288e5c60c309b931b/wal-000000037 (ops 177-181)
I20260812 06:17:55.979092 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: LogGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:55.979619 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:55.997498 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.018s	user 0.009s	sys 0.001s 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:17:55.997958 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:56.008769 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.009294 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b): 448 bytes on disk
I20260812 06:17:56.009749 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: UndoDeltaBlockGCOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.010252 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:56.241376 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.231s	user 0.151s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1228,"lbm_read_time_us":16158,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41672,"lbm_writes_lt_1ms":743,"mutex_wait_us":610,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:17:56.241997 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=18.063937
I20260812 06:17:56.302637 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.060s	user 0.029s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27177,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.303161 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b): perf score=2.188937
I20260812 06:17:56.316248 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: FlushDeltaMemStoresOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.316702 16737 maintenance_manager.cc:419] P 8a6cb6704f5d4e55aae7921395e1b384: Scheduling MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b): perf score=1.000000
I20260812 06:17:56.334812 16080 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.916s	user 1.833s	sys 0.200s
I20260812 06:17:56.388772 16080 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.000s
I20260812 06:17:56.389300 16080 tablet_server.cc:179] TabletServer@127.15.180.1:0 shutting down...
I20260812 06:17:56.471698 16623 maintenance_manager.cc:643] P 8a6cb6704f5d4e55aae7921395e1b384: MajorDeltaCompactionOp(b56ef96b9fe146e288e5c60c309b931b) complete. Timing: real 0.155s	user 0.112s	sys 0.042s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1513,"lbm_read_time_us":11455,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29999,"lbm_writes_lt_1ms":643,"mutex_wait_us":454,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44672,"update_count":3000}
I20260812 06:17:56.472391 16080 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:56.472652 16080 tablet_replica.cc:333] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384: stopping tablet replica
I20260812 06:17:56.472810 16080 raft_consensus.cc:2243] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.473038 16080 raft_consensus.cc:2272] T b56ef96b9fe146e288e5c60c309b931b P 8a6cb6704f5d4e55aae7921395e1b384 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.489070 16080 tablet_server.cc:196] TabletServer@127.15.180.1:0 shutdown complete.
I20260812 06:17:56.524977 16080 master.cc:562] Master@127.15.180.62:42061 shutting down...
I20260812 06:17:56.532744 16080 raft_consensus.cc:2243] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.532955 16080 raft_consensus.cc:2272] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.533053 16080 tablet_replica.cc:333] T 00000000000000000000000000000000 P de9ac6697a39432faf351395ea7bffb0: stopping tablet replica
I20260812 06:17:56.545684 16080 master.cc:584] Master@127.15.180.62:42061 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5439 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10867 ms total)

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