[==========] 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:16:41.270635 29804 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.27.62:42231
I20260812 06:16:41.271773 29804 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:16:41.272492 29804 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.280180 29811 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:16:41.280242 29812 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:41.280274 29804 server_base.cc:1061] running on GCE node
W20260812 06:16:41.280552 29814 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:16:41.281123 29804 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.281273 29804 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:16:41.281342 29804 hybrid_clock.cc:648] HybridClock initialized: now 1786515401281338 us; error 0 us; skew 500 ppm
I20260812 06:16:41.283516 29804 webserver.cc:533] Webserver started at http://127.29.27.62:44941/ using document root <none> and password file <none>
I20260812 06:16:41.284210 29804 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.284412 29804 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.284914 29804 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.286828 29804 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/master-0-root/instance:
uuid: "aeccf962982a45c4a077a431fbd40f03"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-kvfs"
I20260812 06:16:41.290990 29804 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.001s	sys 0.005s
I20260812 06:16:41.293576 29823 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:16:41.295116 29804 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:16:41.295298 29804 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/master-0-root
uuid: "aeccf962982a45c4a077a431fbd40f03"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-kvfs"
I20260812 06:16:41.295436 29804 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-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:16:41.320879 29804 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.321647 29804 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:16:41.321847 29804 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.332082 29804 rpc_server.cc:307] RPC server started. Bound to: 127.29.27.62:42231
I20260812 06:16:41.332320 29902 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.27.62:42231 every 8 connection(s)
I20260812 06:16:41.335165 29904 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:16:41.341375 29904 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: Bootstrap starting.
I20260812 06:16:41.344205 29904 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.345346 29904 log.cc:826] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:41.347384 29904 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: No bootstrap required, opened a new log
I20260812 06:16:41.351275 29904 raft_consensus.cc:359] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER }
I20260812 06:16:41.351487 29904 raft_consensus.cc:385] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.351583 29904 raft_consensus.cc:740] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aeccf962982a45c4a077a431fbd40f03, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.352367 29904 consensus_queue.cc:260] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [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: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER }
I20260812 06:16:41.352542 29904 raft_consensus.cc:399] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.352638 29904 raft_consensus.cc:493] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.352806 29904 raft_consensus.cc:3060] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.353741 29904 raft_consensus.cc:515] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER }
I20260812 06:16:41.354251 29904 leader_election.cc:304] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [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: aeccf962982a45c4a077a431fbd40f03; no voters: 
I20260812 06:16:41.354631 29904 leader_election.cc:290] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.354815 29907 raft_consensus.cc:2804] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.355090 29907 raft_consensus.cc:697] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 1 LEADER]: Becoming Leader. State: Replica: aeccf962982a45c4a077a431fbd40f03, State: Running, Role: LEADER
I20260812 06:16:41.355655 29907 consensus_queue.cc:237] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [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: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER }
I20260812 06:16:41.355974 29904 sys_catalog.cc:565] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:41.357997 29907 sys_catalog.cc:455] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [sys.catalog]: SysCatalogTable state changed. Reason: New leader aeccf962982a45c4a077a431fbd40f03. Latest consensus state: current_term: 1 leader_uuid: "aeccf962982a45c4a077a431fbd40f03" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER } }
I20260812 06:16:41.358356 29907 sys_catalog.cc:458] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.358419 29910 sys_catalog.cc:455] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "aeccf962982a45c4a077a431fbd40f03" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeccf962982a45c4a077a431fbd40f03" member_type: VOTER } }
I20260812 06:16:41.358557 29910 sys_catalog.cc:458] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.358873 29923 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:41.359443 29804 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:41.362159 29923 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:41.367259 29923 catalog_manager.cc:1383] Generated new cluster ID: 70cb55914c69433aa17ebe3399cbb191
I20260812 06:16:41.367342 29923 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:41.385493 29923 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:41.386569 29923 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:41.408571 29923 catalog_manager.cc:6092] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: Generated new TSK 0
I20260812 06:16:41.409443 29923 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:41.425364 29804 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.429570 29941 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:41.429733 29804 server_base.cc:1061] running on GCE node
W20260812 06:16:41.429647 29939 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:16:41.429983 29944 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:16:41.430591 29804 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.430733 29804 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:16:41.430766 29804 hybrid_clock.cc:648] HybridClock initialized: now 1786515401430766 us; error 0 us; skew 500 ppm
I20260812 06:16:41.432266 29804 webserver.cc:533] Webserver started at http://127.29.27.1:43395/ using document root <none> and password file <none>
I20260812 06:16:41.432498 29804 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.432560 29804 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.432698 29804 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.433262 29804 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/instance:
uuid: "80279dc8580c40b3a8b604d66ce63767"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-kvfs"
I20260812 06:16:41.435729 29804 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:41.437665 29951 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:16:41.438058 29804 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:41.438144 29804 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root
uuid: "80279dc8580c40b3a8b604d66ce63767"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-kvfs"
I20260812 06:16:41.438269 29804 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-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:16:41.461386 29804 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.461946 29804 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.462554 29804 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:41.463624 29804 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:41.463683 29804 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.463754 29804 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:41.463796 29804 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.474134 29804 rpc_server.cc:307] RPC server started. Bound to: 127.29.27.1:43069
I20260812 06:16:41.474191 30047 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.27.1:43069 every 8 connection(s)
I20260812 06:16:41.491742 30049 heartbeater.cc:344] Connected to a master server at 127.29.27.62:42231
I20260812 06:16:41.492290 30049 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:41.493132 30049 heartbeater.cc:507] Master 127.29.27.62:42231 requested a full tablet report, sending...
I20260812 06:16:41.495141 29843 ts_manager.cc:194] Registered new tserver with Master: 80279dc8580c40b3a8b604d66ce63767 (127.29.27.1:43069)
I20260812 06:16:41.495711 29804 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020827601s
I20260812 06:16:41.496832 29843 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45844
I20260812 06:16:41.506783 29843 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45860:
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:16:41.523595 29996 tablet_service.cc:1511] Processing CreateTablet for tablet 950d2ba65f934e029ab33e10ea57f46f (DEFAULT_TABLE table=heavy-update-compaction-test [id=bdb195064f0f493c9e965b76469af95e]), partition=
I20260812 06:16:41.524278 29996 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 950d2ba65f934e029ab33e10ea57f46f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:41.527107 30065 tablet_bootstrap.cc:492] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Bootstrap starting.
I20260812 06:16:41.528246 30065 tablet_bootstrap.cc:654] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.530030 30065 tablet_bootstrap.cc:492] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: No bootstrap required, opened a new log
I20260812 06:16:41.530159 30065 ts_tablet_manager.cc:1403] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:41.530741 30065 raft_consensus.cc:359] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80279dc8580c40b3a8b604d66ce63767" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 43069 } }
I20260812 06:16:41.530917 30065 raft_consensus.cc:385] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.530968 30065 raft_consensus.cc:740] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 80279dc8580c40b3a8b604d66ce63767, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.531154 30065 consensus_queue.cc:260] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [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: "80279dc8580c40b3a8b604d66ce63767" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 43069 } }
I20260812 06:16:41.531226 30065 raft_consensus.cc:399] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.531296 30065 raft_consensus.cc:493] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.531353 30065 raft_consensus.cc:3060] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.553155 30065 raft_consensus.cc:515] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80279dc8580c40b3a8b604d66ce63767" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 43069 } }
I20260812 06:16:41.553436 30065 leader_election.cc:304] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [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: 80279dc8580c40b3a8b604d66ce63767; no voters: 
I20260812 06:16:41.553738 30065 leader_election.cc:290] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.554064 30069 raft_consensus.cc:2804] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.554199 30065 ts_tablet_manager.cc:1434] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Time spent starting tablet: real 0.024s	user 0.004s	sys 0.000s
I20260812 06:16:41.554335 30069 raft_consensus.cc:697] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 1 LEADER]: Becoming Leader. State: Replica: 80279dc8580c40b3a8b604d66ce63767, State: Running, Role: LEADER
I20260812 06:16:41.554543 30069 consensus_queue.cc:237] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [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: "80279dc8580c40b3a8b604d66ce63767" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 43069 } }
I20260812 06:16:41.554788 30049 heartbeater.cc:499] Master 127.29.27.62:42231 was elected leader, sending a full tablet report...
I20260812 06:16:41.558620 29843 catalog_manager.cc:5719] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 reported cstate change: term changed from 0 to 1, leader changed from <none> to 80279dc8580c40b3a8b604d66ce63767 (127.29.27.1). New cstate: current_term: 1 leader_uuid: "80279dc8580c40b3a8b604d66ce63767" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80279dc8580c40b3a8b604d66ce63767" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 43069 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:41.633020 29804 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.020s	sys 0.004s
I20260812 06:16:41.725731 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f): perf score=10.125253
I20260812 06:16:41.964805 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.238s	user 0.101s	sys 0.040s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":617,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":47885,"drs_written":1,"lbm_read_time_us":1186,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":3,"lbm_write_time_us":28094,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":183552,"thread_start_us":176,"threads_started":1,"update_count":1050}
I20260812 06:16:41.966329 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f): 8206537 bytes on disk
I20260812 06:16:41.967723 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":135,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.968695 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=9.134250
I20260812 06:16:42.018610 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.050s	user 0.022s	sys 0.009s Metrics: {"bytes_written":10994718,"delete_count":0,"lbm_write_time_us":14368,"lbm_writes_lt_1ms":271,"reinsert_count":0,"update_count":1340}
I20260812 06:16:42.019254 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling LogGCOp(950d2ba65f934e029ab33e10ea57f46f): free 11976772 bytes of WAL
I20260812 06:16:42.019660 29961 log_reader.cc:385] T 950d2ba65f934e029ab33e10ea57f46f: removed 1 log segments from log reader
I20260812 06:16:42.019755 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000001 (ops 1-6)
I20260812 06:16:42.023820 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: LogGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:42.024353 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:42.067345 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.043s	user 0.003s	sys 0.010s Metrics: {"bytes_written":3364213,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:16:42.068100 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:42.167840 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.100s	user 0.006s	sys 0.001s Metrics: {"bytes_written":2051406,"delete_count":0,"lbm_write_time_us":2242,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:16:42.168502 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:42.266438 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.098s	user 0.008s	sys 0.014s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9409,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:42.267786 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=7.149875
I20260812 06:16:42.369022 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.101s	user 0.016s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11684,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:42.369706 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=7.149875
I20260812 06:16:42.467154 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.097s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8820445,"delete_count":0,"lbm_write_time_us":11812,"lbm_writes_lt_1ms":218,"reinsert_count":0,"update_count":1075}
I20260812 06:16:42.467811 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:42.570700 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.103s	user 0.011s	sys 0.012s Metrics: {"bytes_written":7589721,"delete_count":0,"lbm_write_time_us":10185,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:16:42.571565 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:42.676118 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.104s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10121,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:42.676870 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=9.134250
I20260812 06:16:42.777666 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.101s	user 0.022s	sys 0.008s Metrics: {"bytes_written":10707553,"delete_count":0,"lbm_write_time_us":14217,"lbm_writes_lt_1ms":264,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1305}
I20260812 06:16:42.778487 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:42.880417 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.102s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8246104,"delete_count":0,"lbm_write_time_us":10007,"lbm_writes_lt_1ms":204,"reinsert_count":0,"update_count":1005}
I20260812 06:16:42.881310 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=4.173312
I20260812 06:16:42.980792 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.099s	user 0.016s	sys 0.003s Metrics: {"bytes_written":5251345,"delete_count":0,"lbm_write_time_us":6867,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:16:42.982555 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=7.149875
I20260812 06:16:43.016472 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.034s	user 0.022s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":14485,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:43.017128 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:43.029531 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4470,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:43.030073 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:43.765106 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.735s	user 0.490s	sys 0.244s Metrics: {"cfile_cache_miss":2544,"cfile_cache_miss_bytes":106742396,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":14,"delta_iterators_relevant":14,"dirs.queue_time_us":1832,"lbm_read_time_us":49742,"lbm_reads_lt_1ms":2580,"lbm_write_time_us":143551,"lbm_writes_lt_1ms":2545,"mutex_wait_us":377,"peak_mem_usage":311647340,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":490,"threads_started":6,"update_count":12500}
I20260812 06:16:43.766426 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=42.868625
I20260812 06:16:43.955449 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.188s	user 0.102s	sys 0.083s Metrics: {"bytes_written":45537033,"delete_count":0,"lbm_write_time_us":75644,"lbm_writes_lt_1ms":1113,"reinsert_count":0,"update_count":5550}
I20260812 06:16:43.956291 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=10.126437
I20260812 06:16:44.111730 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.155s	user 0.029s	sys 0.012s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":19219,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:44.112607 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=7.149875
I20260812 06:16:44.149345 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.037s	user 0.034s	sys 0.000s Metrics: {"bytes_written":9107635,"delete_count":0,"lbm_write_time_us":14507,"lbm_writes_lt_1ms":225,"reinsert_count":0,"update_count":1110}
I20260812 06:16:44.150101 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:44.176574 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.026s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":6796,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:16:44.177186 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:44.188076 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.188620 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:44.226780 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.038s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1767312,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1411,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2937,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":43}
I20260812 06:16:44.227679 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling LogGCOp(950d2ba65f934e029ab33e10ea57f46f): free 170890656 bytes of WAL
I20260812 06:16:44.227911 29961 log_reader.cc:385] T 950d2ba65f934e029ab33e10ea57f46f: removed 17 log segments from log reader
I20260812 06:16:44.227954 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000002 (ops 7-11)
I20260812 06:16:44.227985 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000003 (ops 12-16)
I20260812 06:16:44.228003 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000004 (ops 17-21)
I20260812 06:16:44.228070 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000005 (ops 22-26)
I20260812 06:16:44.228116 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000006 (ops 27-31)
I20260812 06:16:44.228161 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000007 (ops 32-36)
I20260812 06:16:44.228180 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000008 (ops 37-41)
I20260812 06:16:44.228233 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000009 (ops 42-46)
I20260812 06:16:44.228278 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000010 (ops 47-51)
I20260812 06:16:44.228332 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000011 (ops 52-56)
I20260812 06:16:44.228371 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000012 (ops 57-60)
I20260812 06:16:44.228415 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000013 (ops 61-65)
I20260812 06:16:44.228452 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000014 (ops 66-70)
I20260812 06:16:44.228489 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000015 (ops 71-75)
I20260812 06:16:44.228526 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000016 (ops 76-80)
I20260812 06:16:44.228564 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000017 (ops 81-84)
I20260812 06:16:44.228612 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000018 (ops 85-89)
I20260812 06:16:44.273722 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: LogGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.046s	user 0.000s	sys 0.044s Metrics: {}
I20260812 06:16:44.274297 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:44.304126 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":8123030,"delete_count":0,"lbm_write_time_us":9330,"lbm_writes_lt_1ms":201,"reinsert_count":0,"update_count":990}
I20260812 06:16:44.304800 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling LogGCOp(950d2ba65f934e029ab33e10ea57f46f): free 12017940 bytes of WAL
I20260812 06:16:44.305089 29961 log_reader.cc:385] T 950d2ba65f934e029ab33e10ea57f46f: removed 1 log segments from log reader
I20260812 06:16:44.305154 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000019 (ops 90-94)
I20260812 06:16:44.308097 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: LogGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.003s	user 0.003s	sys 0.000s Metrics: {}
I20260812 06:16:44.308450 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:44.910457 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.602s	user 0.365s	sys 0.236s Metrics: {"cfile_cache_miss":2034,"cfile_cache_miss_bytes":86147380,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":6,"delta_iterators_relevant":6,"dirs.queue_time_us":316,"lbm_read_time_us":44828,"lbm_reads_lt_1ms":2066,"lbm_write_time_us":111114,"lbm_writes_lt_1ms":2043,"peak_mem_usage":248392026,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":635,"threads_started":7,"update_count":9990}
I20260812 06:16:44.911412 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=37.907687
I20260812 06:16:45.089777 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.178s	user 0.069s	sys 0.074s Metrics: {"bytes_written":41106429,"delete_count":0,"lbm_write_time_us":53768,"lbm_writes_lt_1ms":1005,"reinsert_count":0,"update_count":5010}
I20260812 06:16:45.090516 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f): 618 bytes on disk
I20260812 06:16:45.091223 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f) 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:16:45.092208 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=10.126437
I20260812 06:16:45.130461 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16082,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.131363 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:45.515714 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.384s	user 0.226s	sys 0.157s Metrics: {"cfile_cache_miss":1334,"cfile_cache_miss_bytes":57594110,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":897,"lbm_read_time_us":27790,"lbm_reads_lt_1ms":1366,"lbm_write_time_us":71410,"lbm_writes_lt_1ms":1345,"mutex_wait_us":64,"peak_mem_usage":162610546,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":338,"threads_started":5,"update_count":6510}
I20260812 06:16:45.516391 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=26.993625
I20260812 06:16:45.611101 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.094s	user 0.048s	sys 0.042s Metrics: {"bytes_written":29127380,"delete_count":0,"lbm_write_time_us":41581,"lbm_writes_lt_1ms":713,"reinsert_count":0,"update_count":3550}
I20260812 06:16:45.612191 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=6.157687
I20260812 06:16:45.664352 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.052s	user 0.012s	sys 0.017s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":12057,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:45.665136 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:45.682219 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.682790 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:46.008776 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.326s	user 0.197s	sys 0.121s Metrics: {"cfile_cache_miss":1033,"cfile_cache_miss_bytes":45204938,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":307,"lbm_read_time_us":19137,"lbm_reads_lt_1ms":1065,"lbm_write_time_us":57066,"lbm_writes_lt_1ms":1043,"mutex_wait_us":67,"peak_mem_usage":125248760,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":5000}
I20260812 06:16:46.009590 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=22.032687
I20260812 06:16:46.073468 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.064s	user 0.043s	sys 0.019s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":29280,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:16:46.074211 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:46.134068 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushMRSOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.060s	user 0.036s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":5161,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1792}
I20260812 06:16:46.134868 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling LogGCOp(950d2ba65f934e029ab33e10ea57f46f): free 121006546 bytes of WAL
I20260812 06:16:46.135109 29961 log_reader.cc:385] T 950d2ba65f934e029ab33e10ea57f46f: removed 12 log segments from log reader
I20260812 06:16:46.135174 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000020 (ops 95-99)
I20260812 06:16:46.135228 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000021 (ops 100-104)
I20260812 06:16:46.135285 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000022 (ops 105-109)
I20260812 06:16:46.135326 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000023 (ops 110-114)
I20260812 06:16:46.135366 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000024 (ops 115-118)
I20260812 06:16:46.135403 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000025 (ops 119-123)
I20260812 06:16:46.135440 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000026 (ops 124-128)
I20260812 06:16:46.135483 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000027 (ops 129-133)
I20260812 06:16:46.135519 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000028 (ops 134-138)
I20260812 06:16:46.135557 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000029 (ops 139-143)
I20260812 06:16:46.135594 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000030 (ops 144-148)
I20260812 06:16:46.135630 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000031 (ops 149-153)
I20260812 06:16:46.165268 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: LogGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:46.165833 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f): 493 bytes on disk
I20260812 06:16:46.166551 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: UndoDeltaBlockGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:16:46.167197 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=7.149875
I20260812 06:16:46.190321 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.023s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8775,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:46.190953 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling LogGCOp(950d2ba65f934e029ab33e10ea57f46f): free 12017954 bytes of WAL
I20260812 06:16:46.191185 29961 log_reader.cc:385] T 950d2ba65f934e029ab33e10ea57f46f: removed 1 log segments from log reader
I20260812 06:16:46.191229 29961 log.cc:1079] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/950d2ba65f934e029ab33e10ea57f46f/wal-000000032 (ops 154-158)
I20260812 06:16:46.194147 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: LogGCOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:46.194571 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:46.206449 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.206995 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:46.512281 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.305s	user 0.218s	sys 0.075s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41102513,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":310,"lbm_read_time_us":22707,"lbm_reads_lt_1ms":973,"lbm_write_time_us":53941,"lbm_writes_lt_1ms":943,"mutex_wait_us":24,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":27776,"thread_start_us":136,"threads_started":1,"update_count":4500}
I20260812 06:16:46.513610 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=22.032687
I20260812 06:16:46.600466 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.086s	user 0.038s	sys 0.043s Metrics: {"bytes_written":24614721,"delete_count":0,"lbm_write_time_us":36124,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":601,"reinsert_count":0,"update_count":3000}
I20260812 06:16:46.601214 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=3.181125
I20260812 06:16:46.615088 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4841098,"delete_count":0,"lbm_write_time_us":5676,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:16:46.615677 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:46.626109 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3422,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:16:46.627298 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:46.866750 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.239s	user 0.177s	sys 0.060s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37000094,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":239,"lbm_read_time_us":17268,"lbm_reads_lt_1ms":873,"lbm_write_time_us":50818,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":29440,"update_count":4000}
I20260812 06:16:46.867646 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=18.063937
I20260812 06:16:46.925565 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.058s	user 0.033s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25586,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:46.926156 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:46.945245 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.946007 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:47.127552 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.181s	user 0.129s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795172,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":652,"lbm_read_time_us":13629,"lbm_reads_lt_1ms":668,"lbm_write_time_us":36281,"lbm_writes_lt_1ms":643,"mutex_wait_us":309,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:47.128222 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=15.087375
I20260812 06:16:47.190109 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.062s	user 0.039s	sys 0.021s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":27420,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:16:47.190789 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:47.217767 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.027s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5364,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:47.218266 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f): perf score=2.188937
I20260812 06:16:47.229097 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: FlushDeltaMemStoresOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.229585 30050 maintenance_manager.cc:419] P 80279dc8580c40b3a8b604d66ce63767: Scheduling MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f): perf score=1.000000
I20260812 06:16:47.263208 29804 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.630s	user 1.927s	sys 0.192s
I20260812 06:16:47.342669 29804 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.001s	sys 0.000s
I20260812 06:16:47.343407 29804 tablet_server.cc:179] TabletServer@127.29.27.1:0 shutting down...
I20260812 06:16:47.412603 29961 maintenance_manager.cc:643] P 80279dc8580c40b3a8b604d66ce63767: MajorDeltaCompactionOp(950d2ba65f934e029ab33e10ea57f46f) complete. Timing: real 0.183s	user 0.143s	sys 0.039s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795275,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":443,"lbm_read_time_us":14633,"lbm_reads_lt_1ms":669,"lbm_write_time_us":33431,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":54016,"update_count":3000}
I20260812 06:16:47.413671 29804 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:47.414182 29804 tablet_replica.cc:333] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767: stopping tablet replica
I20260812 06:16:47.414462 29804 raft_consensus.cc:2243] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:47.414736 29804 raft_consensus.cc:2272] T 950d2ba65f934e029ab33e10ea57f46f P 80279dc8580c40b3a8b604d66ce63767 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:47.421514 29804 tablet_server.cc:196] TabletServer@127.29.27.1:0 shutdown complete.
I20260812 06:16:47.470206 29804 master.cc:562] Master@127.29.27.62:42231 shutting down...
I20260812 06:16:47.474766 29804 raft_consensus.cc:2243] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:47.475133 29804 raft_consensus.cc:2272] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:47.475335 29804 tablet_replica.cc:333] T 00000000000000000000000000000000 P aeccf962982a45c4a077a431fbd40f03: stopping tablet replica
I20260812 06:16:47.488958 29804 master.cc:584] Master@127.29.27.62:42231 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6323 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:47.593008 29804 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.27.62:34241
I20260812 06:16:47.593433 29804 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:47.595922 30121 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:16:47.596161 30120 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:16:47.596172 30123 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:16:47.596477 29804 server_base.cc:1061] running on GCE node
I20260812 06:16:47.596658 29804 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.596724 29804 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:16:47.596757 29804 hybrid_clock.cc:648] HybridClock initialized: now 1786515407596756 us; error 0 us; skew 500 ppm
I20260812 06:16:47.597934 29804 webserver.cc:533] Webserver started at http://127.29.27.62:37775/ using document root <none> and password file <none>
I20260812 06:16:47.598135 29804 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.598218 29804 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.598301 29804 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.598757 29804 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/master-0-root/instance:
uuid: "b5ca3a88c39c41cdabb5a78f24221779"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-kvfs"
I20260812 06:16:47.600485 29804 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:47.601598 30129 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:16:47.601945 29804 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:47.602028 29804 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/master-0-root
uuid: "b5ca3a88c39c41cdabb5a78f24221779"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-kvfs"
I20260812 06:16:47.602092 29804 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-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:16:47.607246 29804 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.607653 29804 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.612916 29804 rpc_server.cc:307] RPC server started. Bound to: 127.29.27.62:34241
I20260812 06:16:47.616933 30223 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.27.62:34241 every 8 connection(s)
I20260812 06:16:47.622937 30227 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:16:47.625303 30227 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779: Bootstrap starting.
I20260812 06:16:47.626255 30227 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.627612 30227 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779: No bootstrap required, opened a new log
I20260812 06:16:47.628218 30227 raft_consensus.cc:359] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER }
I20260812 06:16:47.628357 30227 raft_consensus.cc:385] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.628415 30227 raft_consensus.cc:740] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b5ca3a88c39c41cdabb5a78f24221779, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.628618 30227 consensus_queue.cc:260] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [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: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER }
I20260812 06:16:47.628726 30227 raft_consensus.cc:399] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.628782 30227 raft_consensus.cc:493] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.628844 30227 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.629755 30227 raft_consensus.cc:515] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER }
I20260812 06:16:47.629952 30227 leader_election.cc:304] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [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: b5ca3a88c39c41cdabb5a78f24221779; no voters: 
I20260812 06:16:47.630214 30227 leader_election.cc:290] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.630458 30231 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.630774 30231 raft_consensus.cc:697] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 1 LEADER]: Becoming Leader. State: Replica: b5ca3a88c39c41cdabb5a78f24221779, State: Running, Role: LEADER
I20260812 06:16:47.630846 30227 sys_catalog.cc:565] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:47.630973 30231 consensus_queue.cc:237] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [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: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER }
I20260812 06:16:47.631577 30233 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b5ca3a88c39c41cdabb5a78f24221779. Latest consensus state: current_term: 1 leader_uuid: "b5ca3a88c39c41cdabb5a78f24221779" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER } }
I20260812 06:16:47.631713 30233 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.631906 30232 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b5ca3a88c39c41cdabb5a78f24221779" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5ca3a88c39c41cdabb5a78f24221779" member_type: VOTER } }
I20260812 06:16:47.632282 30232 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.632921 30239 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:47.633981 30239 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:47.634264 29804 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:47.636510 30239 catalog_manager.cc:1383] Generated new cluster ID: d611597acc07481c8863de82da62c26f
I20260812 06:16:47.636591 30239 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:47.653635 30239 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:47.654434 30239 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:47.664446 30239 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779: Generated new TSK 0
I20260812 06:16:47.664685 30239 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:47.666860 29804 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:47.669587 30253 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:16:47.669606 30259 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:16:47.669902 29804 server_base.cc:1061] running on GCE node
W20260812 06:16:47.669636 30255 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:47.670333 29804 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.670404 29804 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:16:47.670430 29804 hybrid_clock.cc:648] HybridClock initialized: now 1786515407670430 us; error 0 us; skew 500 ppm
I20260812 06:16:47.671394 29804 webserver.cc:533] Webserver started at http://127.29.27.1:35751/ using document root <none> and password file <none>
I20260812 06:16:47.671619 29804 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.671700 29804 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.671782 29804 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.672282 29804 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/instance:
uuid: "ab84abc477114e62910360ef07e1d26b"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-kvfs"
I20260812 06:16:47.673911 29804 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:47.675014 30266 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:16:47.675282 29804 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:47.675379 29804 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root
uuid: "ab84abc477114e62910360ef07e1d26b"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-kvfs"
I20260812 06:16:47.675516 29804 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-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:16:47.681044 29804 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.681638 29804 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.682154 29804 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:47.682814 29804 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:47.682885 29804 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.683189 29804 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:47.683277 29804 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.690287 29804 rpc_server.cc:307] RPC server started. Bound to: 127.29.27.1:39225
I20260812 06:16:47.691310 30376 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.27.1:39225 every 8 connection(s)
I20260812 06:16:47.704622 30377 heartbeater.cc:344] Connected to a master server at 127.29.27.62:34241
I20260812 06:16:47.704768 30377 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:47.705036 30377 heartbeater.cc:507] Master 127.29.27.62:34241 requested a full tablet report, sending...
I20260812 06:16:47.705826 30158 ts_manager.cc:194] Registered new tserver with Master: ab84abc477114e62910360ef07e1d26b (127.29.27.1:39225)
I20260812 06:16:47.706363 29804 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014905076s
I20260812 06:16:47.706918 30158 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33684
I20260812 06:16:47.715245 30158 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33686:
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:16:47.726217 30319 tablet_service.cc:1511] Processing CreateTablet for tablet 53216535280e42ab88ae34e9109f7091 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a588e157ab7a45faa80aa59ca9e7925d]), partition=
I20260812 06:16:47.726553 30319 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 53216535280e42ab88ae34e9109f7091. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:47.729053 30401 tablet_bootstrap.cc:492] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Bootstrap starting.
I20260812 06:16:47.730103 30401 tablet_bootstrap.cc:654] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.731534 30401 tablet_bootstrap.cc:492] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: No bootstrap required, opened a new log
I20260812 06:16:47.731639 30401 ts_tablet_manager.cc:1403] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:47.732354 30401 raft_consensus.cc:359] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab84abc477114e62910360ef07e1d26b" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 39225 } }
I20260812 06:16:47.732510 30401 raft_consensus.cc:385] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.732577 30401 raft_consensus.cc:740] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ab84abc477114e62910360ef07e1d26b, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.732764 30401 consensus_queue.cc:260] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [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: "ab84abc477114e62910360ef07e1d26b" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 39225 } }
I20260812 06:16:47.732883 30401 raft_consensus.cc:399] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.732932 30401 raft_consensus.cc:493] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.733170 30401 raft_consensus.cc:3060] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.734385 30401 raft_consensus.cc:515] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab84abc477114e62910360ef07e1d26b" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 39225 } }
I20260812 06:16:47.734615 30401 leader_election.cc:304] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [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: ab84abc477114e62910360ef07e1d26b; no voters: 
I20260812 06:16:47.734923 30401 leader_election.cc:290] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.735157 30404 raft_consensus.cc:2804] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.735339 30401 ts_tablet_manager.cc:1434] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:16:47.735373 30377 heartbeater.cc:499] Master 127.29.27.62:34241 was elected leader, sending a full tablet report...
I20260812 06:16:47.735430 30404 raft_consensus.cc:697] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 1 LEADER]: Becoming Leader. State: Replica: ab84abc477114e62910360ef07e1d26b, State: Running, Role: LEADER
I20260812 06:16:47.735626 30404 consensus_queue.cc:237] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [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: "ab84abc477114e62910360ef07e1d26b" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 39225 } }
I20260812 06:16:47.737151 30158 catalog_manager.cc:5719] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b reported cstate change: term changed from 0 to 1, leader changed from <none> to ab84abc477114e62910360ef07e1d26b (127.29.27.1). New cstate: current_term: 1 leader_uuid: "ab84abc477114e62910360ef07e1d26b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab84abc477114e62910360ef07e1d26b" member_type: VOTER last_known_addr { host: "127.29.27.1" port: 39225 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:47.805048 29804 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.013s	sys 0.013s
I20260812 06:16:47.942044 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushMRSOp(53216535280e42ab88ae34e9109f7091): perf score=15.086190
I20260812 06:16:48.102479 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushMRSOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.160s	user 0.086s	sys 0.071s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":121,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":881,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39784,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:16:48.103304 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 11976772 bytes of WAL
I20260812 06:16:48.103576 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 1 log segments from log reader
I20260812 06:16:48.103626 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000001 (ops 1-6)
I20260812 06:16:48.106468 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:48.106832 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091): 12308957 bytes on disk
I20260812 06:16:48.107337 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.107890 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:48.121423 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.121959 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:48.331300 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.209s	user 0.137s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":13514,"lbm_reads_lt_1ms":464,"lbm_write_time_us":32961,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":359,"threads_started":5,"update_count":2000}
I20260812 06:16:48.331892 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:48.403307 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.071s	user 0.029s	sys 0.038s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26239,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.404258 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:48.416352 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.416869 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:48.608973 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.192s	user 0.108s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1168,"lbm_read_time_us":14106,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30780,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:48.609848 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=11.118625
I20260812 06:16:48.668704 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.059s	user 0.042s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":23955,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:16:48.669272 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:48.684717 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.685271 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:48.710325 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.025s	user 0.012s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:48.714350 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:48.938943 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.224s	user 0.143s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":363,"lbm_read_time_us":16272,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34971,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:16:48.939548 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:49.000507 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.061s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21933,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:49.001077 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:49.012588 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4460,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.013145 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:49.210182 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.197s	user 0.141s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":958,"lbm_read_time_us":12043,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36164,"lbm_writes_lt_1ms":543,"mutex_wait_us":353,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":235520,"update_count":2500}
I20260812 06:16:49.210950 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:49.266000 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.055s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409912,"delete_count":0,"lbm_write_time_us":23187,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:49.266566 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:49.279449 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4851,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.280263 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:49.439507 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.159s	user 0.122s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":11459,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31980,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:16:49.440301 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=10.126437
I20260812 06:16:49.478415 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.038s	user 0.014s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.478940 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:49.495149 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.495911 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushMRSOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:49.527019 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushMRSOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.031s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1427,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1587,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:49.527637 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 112692356 bytes of WAL
I20260812 06:16:49.527886 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 11 log segments from log reader
I20260812 06:16:49.527930 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000002 (ops 7-11)
I20260812 06:16:49.527958 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000003 (ops 12-16)
I20260812 06:16:49.528046 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000004 (ops 17-21)
I20260812 06:16:49.528090 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000005 (ops 22-26)
I20260812 06:16:49.528119 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000006 (ops 27-31)
I20260812 06:16:49.528162 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000007 (ops 32-36)
I20260812 06:16:49.528223 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000008 (ops 37-41)
I20260812 06:16:49.528262 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000009 (ops 42-46)
I20260812 06:16:49.528301 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000010 (ops 47-51)
I20260812 06:16:49.528337 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000011 (ops 52-56)
I20260812 06:16:49.528373 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000012 (ops 57-61)
I20260812 06:16:49.554282 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:16:49.554900 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091): 447 bytes on disk
I20260812 06:16:49.555423 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:49.556216 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=3.181125
I20260812 06:16:49.571630 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.015s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:49.572152 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:49.585217 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:49.585801 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:49.777081 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.191s	user 0.163s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":709,"lbm_read_time_us":12997,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37836,"lbm_writes_lt_1ms":643,"mutex_wait_us":283,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8064,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:16:49.777886 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:49.837224 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.059s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:49.837909 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:49.855103 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.855774 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:50.055017 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.199s	user 0.126s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":379,"lbm_read_time_us":12324,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35317,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:16:50.055727 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:50.119526 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.064s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26733,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:50.120297 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:50.136196 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4650,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.137234 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:50.326066 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.189s	user 0.141s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":13141,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37935,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:16:50.327044 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=11.118625
I20260812 06:16:50.371476 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.044s	user 0.035s	sys 0.006s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18604,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:50.372467 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:50.397444 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.025s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5093,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:50.398167 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:50.411221 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.412189 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:50.600581 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.188s	user 0.146s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":300,"lbm_read_time_us":10742,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38245,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:16:50.601464 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:50.657716 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.056s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23191,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:50.658372 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:50.675824 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.676860 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:50.862852 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.185s	user 0.133s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":13443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33648,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:16:50.863597 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:50.934973 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.071s	user 0.045s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27222,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:50.935866 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:50.956100 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.020s	user 0.016s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.957208 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:51.151295 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.194s	user 0.121s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":12858,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32533,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:16:51.152014 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:51.205130 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.053s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.205720 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushMRSOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:51.235930 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushMRSOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":134,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1421,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1725,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:51.236732 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 132571314 bytes of WAL
I20260812 06:16:51.236980 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 13 log segments from log reader
I20260812 06:16:51.237025 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000013 (ops 62-66)
I20260812 06:16:51.237056 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000014 (ops 67-70)
I20260812 06:16:51.237073 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000015 (ops 71-75)
I20260812 06:16:51.237131 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000016 (ops 76-80)
I20260812 06:16:51.237176 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000017 (ops 81-85)
I20260812 06:16:51.237203 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000018 (ops 86-90)
I20260812 06:16:51.237252 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000019 (ops 91-94)
I20260812 06:16:51.237295 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000020 (ops 95-99)
I20260812 06:16:51.237355 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000021 (ops 100-104)
I20260812 06:16:51.237397 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000022 (ops 105-109)
I20260812 06:16:51.237452 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000023 (ops 110-114)
I20260812 06:16:51.237493 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000024 (ops 115-119)
I20260812 06:16:51.237524 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000025 (ops 120-124)
I20260812 06:16:51.273270 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.036s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:16:51.273927 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=6.157687
I20260812 06:16:51.298858 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.025s	user 0.009s	sys 0.012s Metrics: {"bytes_written":7507666,"delete_count":0,"lbm_write_time_us":10356,"lbm_writes_lt_1ms":186,"reinsert_count":0,"update_count":915}
I20260812 06:16:51.299758 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 8767120 bytes of WAL
I20260812 06:16:51.300253 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 1 log segments from log reader
I20260812 06:16:51.300385 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000026 (ops 125-129)
I20260812 06:16:51.302546 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:51.303046 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091): 493 bytes on disk
I20260812 06:16:51.303556 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:16:51.304421 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:51.545743 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.241s	user 0.151s	sys 0.085s Metrics: {"cfile_cache_miss":615,"cfile_cache_miss_bytes":28138726,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1441,"lbm_read_time_us":14575,"lbm_reads_lt_1ms":647,"lbm_write_time_us":43855,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":624,"mutex_wait_us":347,"peak_mem_usage":72764109,"reinsert_count":0,"spinlock_wait_cycles":28544,"thread_start_us":139,"threads_started":1,"update_count":2915}
I20260812 06:16:51.547407 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=17.071750
I20260812 06:16:51.612771 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.065s	user 0.040s	sys 0.020s Metrics: {"bytes_written":18666237,"delete_count":0,"lbm_write_time_us":27418,"lbm_writes_lt_1ms":458,"reinsert_count":0,"update_count":2275}
I20260812 06:16:51.613443 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=1.196750
I20260812 06:16:51.629360 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.016s	user 0.009s	sys 0.003s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":5040,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:16:51.629944 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:51.641352 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.641950 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:51.860602 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.218s	user 0.160s	sys 0.059s Metrics: {"cfile_cache_miss":650,"cfile_cache_miss_bytes":29533636,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":227,"lbm_read_time_us":14949,"lbm_reads_lt_1ms":690,"lbm_write_time_us":37520,"lbm_writes_lt_1ms":660,"mutex_wait_us":45,"peak_mem_usage":77280451,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":3085}
I20260812 06:16:51.865190 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=15.087375
I20260812 06:16:51.909873 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.044s	user 0.017s	sys 0.025s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":19155,"lbm_writes_lt_1ms":413,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2050}
I20260812 06:16:51.910404 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:51.941052 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.030s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6137,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.941545 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:51.952540 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.953069 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:52.190212 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.237s	user 0.143s	sys 0.088s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836243,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":876,"lbm_read_time_us":18420,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36320,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":851840,"update_count":3000}
I20260812 06:16:52.191293 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=16.079562
I20260812 06:16:52.256247 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.065s	user 0.044s	sys 0.020s Metrics: {"bytes_written":17927795,"delete_count":0,"lbm_write_time_us":28522,"lbm_writes_lt_1ms":440,"reinsert_count":0,"update_count":2185}
I20260812 06:16:52.256960 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=1.196750
I20260812 06:16:52.279126 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.022s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:16:52.279644 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:52.290385 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3681,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:52.291056 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:52.531816 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.241s	user 0.160s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":560,"lbm_read_time_us":17012,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40770,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":3000}
I20260812 06:16:52.532904 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:52.583478 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.050s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22322,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:52.584401 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:52.603703 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.604312 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:52.782809 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.178s	user 0.125s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1235,"lbm_read_time_us":12373,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29226,"lbm_writes_lt_1ms":543,"mutex_wait_us":407,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":43392,"update_count":2500}
I20260812 06:16:52.783371 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=14.095187
I20260812 06:16:52.853984 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.070s	user 0.040s	sys 0.027s Metrics: {"bytes_written":16409884,"delete_count":0,"lbm_write_time_us":31200,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.854590 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:52.866454 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.012s	user 0.006s	sys 0.003s 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:16:52.866997 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushMRSOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:52.906114 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushMRSOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.039s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1975,"drs_written":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:52.906944 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 112692637 bytes of WAL
I20260812 06:16:52.907181 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 11 log segments from log reader
I20260812 06:16:52.907243 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000027 (ops 130-134)
I20260812 06:16:52.907297 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000028 (ops 135-139)
I20260812 06:16:52.907353 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000029 (ops 140-144)
I20260812 06:16:52.907393 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000030 (ops 145-149)
I20260812 06:16:52.907433 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000031 (ops 150-154)
I20260812 06:16:52.907482 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000032 (ops 155-159)
I20260812 06:16:52.907529 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000033 (ops 160-164)
I20260812 06:16:52.907565 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000034 (ops 165-169)
I20260812 06:16:52.907666 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000035 (ops 170-174)
I20260812 06:16:52.907716 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000036 (ops 175-179)
I20260812 06:16:52.907764 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000037 (ops 180-184)
I20260812 06:16:52.934010 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:52.934484 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:52.949927 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":5166,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:16:52.950526 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling LogGCOp(53216535280e42ab88ae34e9109f7091): free 11564893 bytes of WAL
I20260812 06:16:52.950736 30272 log_reader.cc:385] T 53216535280e42ab88ae34e9109f7091: removed 1 log segments from log reader
I20260812 06:16:52.950784 30272 log.cc:1079] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: Deleting log segment in path: /tmp/dist-test-taskvbakqm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401257369-29804-0/minicluster-data/ts-0-root/wals/53216535280e42ab88ae34e9109f7091/wal-000000038 (ops 185-188)
I20260812 06:16:52.953274 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: LogGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:52.953743 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091): 463 bytes on disk
I20260812 06:16:52.954241 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: UndoDeltaBlockGCOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.954815 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:52.970374 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":5534,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:16:52.970955 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:53.224117 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.253s	user 0.151s	sys 0.099s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938767,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":222,"lbm_read_time_us":19460,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45052,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":147,"threads_started":1,"update_count":3500}
I20260812 06:16:53.224814 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=18.063937
I20260812 06:16:53.294665 29804 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.489s	user 2.051s	sys 0.163s
I20260812 06:16:53.298815 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.073s	user 0.050s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":33382,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:53.299633 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091): perf score=2.188937
I20260812 06:16:53.317425 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: FlushDeltaMemStoresOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":500}
I20260812 06:16:53.318060 30379 maintenance_manager.cc:419] P ab84abc477114e62910360ef07e1d26b: Scheduling MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091): perf score=1.000000
I20260812 06:16:53.370833 29804 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:16:53.371462 29804 tablet_server.cc:179] TabletServer@127.29.27.1:0 shutting down...
I20260812 06:16:53.479737 30272 maintenance_manager.cc:643] P ab84abc477114e62910360ef07e1d26b: MajorDeltaCompactionOp(53216535280e42ab88ae34e9109f7091) complete. Timing: real 0.161s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_hit":416,"cfile_cache_hit_bytes":17026245,"cfile_cache_miss":216,"cfile_cache_miss_bytes":11809890,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1197,"lbm_read_time_us":6695,"lbm_reads_lt_1ms":248,"lbm_write_time_us":32147,"lbm_writes_lt_1ms":643,"mutex_wait_us":102,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":48640,"update_count":3000}
I20260812 06:16:53.480512 29804 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:53.480788 29804 tablet_replica.cc:333] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b: stopping tablet replica
I20260812 06:16:53.481160 29804 raft_consensus.cc:2243] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:53.481602 29804 raft_consensus.cc:2272] T 53216535280e42ab88ae34e9109f7091 P ab84abc477114e62910360ef07e1d26b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:53.487977 29804 tablet_server.cc:196] TabletServer@127.29.27.1:0 shutdown complete.
I20260812 06:16:53.536952 29804 master.cc:562] Master@127.29.27.62:34241 shutting down...
I20260812 06:16:53.541042 29804 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:53.541265 29804 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:53.541324 29804 tablet_replica.cc:333] T 00000000000000000000000000000000 P b5ca3a88c39c41cdabb5a78f24221779: stopping tablet replica
I20260812 06:16:53.554580 29804 master.cc:584] Master@127.29.27.62:34241 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6061 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12385 ms total)

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