[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:30.990082  8526 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.83.190:34539
I20260812 06:19:30.991127  8526 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:30.991748  8526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:30.997936  8534 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:30.998003  8531 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:30.998185  8526 server_base.cc:1061] running on GCE node
W20260812 06:19:30.998288  8532 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:30.998816  8526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:30.998925  8526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:30.998958  8526 hybrid_clock.cc:648] HybridClock initialized: now 1786515570998957 us; error 0 us; skew 500 ppm
I20260812 06:19:31.000828  8526 webserver.cc:533] Webserver started at http://127.8.83.190:35401/ using document root <none> and password file <none>
I20260812 06:19:31.001325  8526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.001379  8526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.001572  8526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.003232  8526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/master-0-root/instance:
uuid: "33000d8ecc434a2dbd79402ea2f47132"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-1jjb"
I20260812 06:19:31.006834  8526 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:31.008873  8541 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.009884  8526 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:31.009989  8526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/master-0-root
uuid: "33000d8ecc434a2dbd79402ea2f47132"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-1jjb"
I20260812 06:19:31.010069  8526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.032374  8526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.033032  8526 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:31.033176  8526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.040831  8526 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.190:34539
I20260812 06:19:31.040861  8597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.190:34539 every 8 connection(s)
I20260812 06:19:31.043052  8598 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.048379  8598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: Bootstrap starting.
I20260812 06:19:31.050679  8598 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.051551  8598 log.cc:826] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:31.053203  8598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: No bootstrap required, opened a new log
I20260812 06:19:31.055871  8598 raft_consensus.cc:359] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER }
I20260812 06:19:31.056022  8598 raft_consensus.cc:385] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.056061  8598 raft_consensus.cc:740] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 33000d8ecc434a2dbd79402ea2f47132, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.056631  8598 consensus_queue.cc:260] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [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: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER }
I20260812 06:19:31.056790  8598 raft_consensus.cc:399] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.056880  8598 raft_consensus.cc:493] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.057054  8598 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.057789  8598 raft_consensus.cc:515] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER }
I20260812 06:19:31.058207  8598 leader_election.cc:304] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [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: 33000d8ecc434a2dbd79402ea2f47132; no voters: 
I20260812 06:19:31.058501  8598 leader_election.cc:290] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.058629  8603 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.058871  8603 raft_consensus.cc:697] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 1 LEADER]: Becoming Leader. State: Replica: 33000d8ecc434a2dbd79402ea2f47132, State: Running, Role: LEADER
I20260812 06:19:31.059321  8603 consensus_queue.cc:237] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [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: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER }
I20260812 06:19:31.059434  8598 sys_catalog.cc:565] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:31.061233  8605 sys_catalog.cc:455] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 33000d8ecc434a2dbd79402ea2f47132. Latest consensus state: current_term: 1 leader_uuid: "33000d8ecc434a2dbd79402ea2f47132" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER } }
I20260812 06:19:31.061287  8604 sys_catalog.cc:455] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "33000d8ecc434a2dbd79402ea2f47132" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "33000d8ecc434a2dbd79402ea2f47132" member_type: VOTER } }
I20260812 06:19:31.061363  8605 sys_catalog.cc:458] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.061368  8604 sys_catalog.cc:458] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.061750  8621 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:31.061800  8526 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:31.064153  8621 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:31.068324  8621 catalog_manager.cc:1383] Generated new cluster ID: 5c3c193ce70c4dafb19aa02d9781fd21
I20260812 06:19:31.068383  8621 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:31.081316  8621 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:31.082394  8621 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:31.100407  8621 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: Generated new TSK 0
I20260812 06:19:31.101233  8621 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:31.126679  8526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.129385  8627 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.129397  8630 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.129614  8628 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.129776  8526 server_base.cc:1061] running on GCE node
I20260812 06:19:31.129977  8526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.130033  8526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:31.130061  8526 hybrid_clock.cc:648] HybridClock initialized: now 1786515571130061 us; error 0 us; skew 500 ppm
I20260812 06:19:31.131044  8526 webserver.cc:533] Webserver started at http://127.8.83.129:33231/ using document root <none> and password file <none>
I20260812 06:19:31.131212  8526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.131283  8526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.131361  8526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.131755  8526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/instance:
uuid: "43d0f2eb73e944d397e4368be19c9e9f"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1jjb"
I20260812 06:19:31.133304  8526 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:31.134284  8636 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.134531  8526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:31.134600  8526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root
uuid: "43d0f2eb73e944d397e4368be19c9e9f"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1jjb"
I20260812 06:19:31.134684  8526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.143025  8526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.143447  8526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.143949  8526 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:31.144871  8526 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:31.144924  8526 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.144991  8526 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:31.145032  8526 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.151739  8526 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.129:32971
I20260812 06:19:31.151790  8705 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.129:32971 every 8 connection(s)
I20260812 06:19:31.166630  8706 heartbeater.cc:344] Connected to a master server at 127.8.83.190:34539
I20260812 06:19:31.166919  8706 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:31.167421  8706 heartbeater.cc:507] Master 127.8.83.190:34539 requested a full tablet report, sending...
I20260812 06:19:31.168922  8558 ts_manager.cc:194] Registered new tserver with Master: 43d0f2eb73e944d397e4368be19c9e9f (127.8.83.129:32971)
I20260812 06:19:31.169207  8526 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016705958s
I20260812 06:19:31.170440  8558 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52882
I20260812 06:19:31.178869  8558 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52888:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:31.192884  8667 tablet_service.cc:1511] Processing CreateTablet for tablet dbea16c462074c14b15b7cca19360b5b (DEFAULT_TABLE table=heavy-update-compaction-test [id=7b86101262f94639bd93b6f61e116b16]), partition=
I20260812 06:19:31.193356  8667 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dbea16c462074c14b15b7cca19360b5b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.195747  8720 tablet_bootstrap.cc:492] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Bootstrap starting.
I20260812 06:19:31.197508  8720 tablet_bootstrap.cc:654] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.198787  8720 tablet_bootstrap.cc:492] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: No bootstrap required, opened a new log
I20260812 06:19:31.198907  8720 ts_tablet_manager.cc:1403] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:31.199393  8720 raft_consensus.cc:359] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43d0f2eb73e944d397e4368be19c9e9f" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 32971 } }
I20260812 06:19:31.199510  8720 raft_consensus.cc:385] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.199534  8720 raft_consensus.cc:740] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 43d0f2eb73e944d397e4368be19c9e9f, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.199734  8720 consensus_queue.cc:260] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [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: "43d0f2eb73e944d397e4368be19c9e9f" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 32971 } }
I20260812 06:19:31.199826  8720 raft_consensus.cc:399] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.199880  8720 raft_consensus.cc:493] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.199936  8720 raft_consensus.cc:3060] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.200839  8720 raft_consensus.cc:515] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43d0f2eb73e944d397e4368be19c9e9f" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 32971 } }
I20260812 06:19:31.201007  8720 leader_election.cc:304] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [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: 43d0f2eb73e944d397e4368be19c9e9f; no voters: 
I20260812 06:19:31.201263  8720 leader_election.cc:290] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.201377  8723 raft_consensus.cc:2804] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.201607  8723 raft_consensus.cc:697] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 1 LEADER]: Becoming Leader. State: Replica: 43d0f2eb73e944d397e4368be19c9e9f, State: Running, Role: LEADER
I20260812 06:19:31.201752  8720 ts_tablet_manager.cc:1434] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:31.201804  8723 consensus_queue.cc:237] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [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: "43d0f2eb73e944d397e4368be19c9e9f" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 32971 } }
I20260812 06:19:31.201953  8706 heartbeater.cc:499] Master 127.8.83.190:34539 was elected leader, sending a full tablet report...
I20260812 06:19:31.204921  8558 catalog_manager.cc:5719] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f reported cstate change: term changed from 0 to 1, leader changed from <none> to 43d0f2eb73e944d397e4368be19c9e9f (127.8.83.129). New cstate: current_term: 1 leader_uuid: "43d0f2eb73e944d397e4368be19c9e9f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43d0f2eb73e944d397e4368be19c9e9f" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 32971 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:31.271250  8526 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.019s	sys 0.008s
I20260812 06:19:31.402926  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushMRSOp(dbea16c462074c14b15b7cca19360b5b): perf score=19.054940
I20260812 06:19:31.588768  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushMRSOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.185s	user 0.147s	sys 0.028s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":211,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":992,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44730,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":120,"threads_started":1,"update_count":1500}
I20260812 06:19:31.590190  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling LogGCOp(dbea16c462074c14b15b7cca19360b5b): free 20743880 bytes of WAL
I20260812 06:19:31.590633  8641 log_reader.cc:385] T dbea16c462074c14b15b7cca19360b5b: removed 2 log segments from log reader
I20260812 06:19:31.590765  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000001 (ops 1-6)
I20260812 06:19:31.590889  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000002 (ops 7-11)
I20260812 06:19:31.595965  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: LogGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:31.596408  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:31.618417  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.022s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6340,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.618920  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:31.754912  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.136s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":481,"lbm_read_time_us":7683,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22409,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":279,"threads_started":5,"update_count":2000}
I20260812 06:19:31.755546  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:31.791718  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15373,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.792315  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:31.807407  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.808008  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:31.932847  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.125s	user 0.100s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":8830,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25558,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29696,"update_count":2000}
I20260812 06:19:31.933434  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b): 16411392 bytes on disk
I20260812 06:19:31.933885  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.934311  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:31.980537  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.046s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16757,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.981019  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:31.991520  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.992256  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:32.110076  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.118s	user 0.093s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":900,"lbm_read_time_us":8195,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24835,"lbm_writes_lt_1ms":443,"mutex_wait_us":270,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:32.110747  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:32.165699  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.055s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17068,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:32.166234  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.177066  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.177479  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:32.334151  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.157s	user 0.100s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":432,"lbm_read_time_us":11556,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24897,"lbm_writes_lt_1ms":443,"mutex_wait_us":97,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:32.334782  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:32.385273  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.050s	user 0.024s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18390,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.385821  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.400779  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.401396  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:32.525460  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.124s	user 0.109s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":8581,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25100,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:19:32.526048  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:32.570523  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.044s	user 0.032s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17764,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.570967  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.582383  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.582901  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:32.707791  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.125s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":10747,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23361,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:32.708467  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:32.759390  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.051s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14899,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.759910  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.770608  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.771205  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushMRSOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:32.807492  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushMRSOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.036s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":289,"dirs.run_wall_time_us":1321,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1433,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:32.808379  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling LogGCOp(dbea16c462074c14b15b7cca19360b5b): free 112692367 bytes of WAL
I20260812 06:19:32.808641  8641 log_reader.cc:385] T dbea16c462074c14b15b7cca19360b5b: removed 11 log segments from log reader
I20260812 06:19:32.808704  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000003 (ops 12-16)
I20260812 06:19:32.808745  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000004 (ops 17-21)
I20260812 06:19:32.808780  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000005 (ops 22-26)
I20260812 06:19:32.808802  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000006 (ops 27-31)
I20260812 06:19:32.808825  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000007 (ops 32-36)
I20260812 06:19:32.808853  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000008 (ops 37-41)
I20260812 06:19:32.808888  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000009 (ops 42-46)
I20260812 06:19:32.808919  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000010 (ops 47-51)
I20260812 06:19:32.808948  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000011 (ops 52-56)
I20260812 06:19:32.808976  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000012 (ops 57-61)
I20260812 06:19:32.809005  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000013 (ops 62-66)
I20260812 06:19:32.839998  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: LogGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.031s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:19:32.840471  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b): 447 bytes on disk
I20260812 06:19:32.840945  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.841434  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.864969  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.023s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.865377  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:32.875679  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.876145  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.069068  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.193s	user 0.135s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":238,"lbm_read_time_us":13849,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32578,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32640,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:33.071025  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:33.124013  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.053s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.124571  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.278144  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.153s	user 0.113s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":182,"lbm_read_time_us":9931,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26964,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.278764  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=11.118625
I20260812 06:19:33.314785  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.036s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15972,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:33.315587  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:33.331380  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5339,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:33.331842  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.468593  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.137s	user 0.112s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":800,"lbm_read_time_us":9031,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24240,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:33.469332  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:33.505462  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.036s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15179,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.505988  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.624650  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.118s	user 0.069s	sys 0.044s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1416,"lbm_read_time_us":7281,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20033,"lbm_writes_lt_1ms":343,"mutex_wait_us":66,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":733568,"update_count":1500}
I20260812 06:19:33.625470  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:33.661928  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.036s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15348,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.662403  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.789542  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.127s	user 0.090s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":940,"lbm_read_time_us":10046,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20617,"lbm_writes_lt_1ms":343,"mutex_wait_us":352,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":1500}
I20260812 06:19:33.790220  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:33.836175  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.046s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20501,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.836675  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:33.848858  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.849371  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:33.973554  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.123s	user 0.070s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":8841,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24593,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:33.975425  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:34.017858  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.042s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.018445  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:34.035028  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.035568  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:34.167541  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.132s	user 0.099s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":9884,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25381,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:19:34.168274  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=11.118625
I20260812 06:19:34.212775  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.044s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15235,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:34.213544  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:34.229791  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.016s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.230350  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushMRSOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:34.289012  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushMRSOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.058s	user 0.032s	sys 0.005s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1384,"drs_written":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1662,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":8960}
I20260812 06:19:34.289736  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling LogGCOp(dbea16c462074c14b15b7cca19360b5b): free 111786208 bytes of WAL
I20260812 06:19:34.289970  8641 log_reader.cc:385] T dbea16c462074c14b15b7cca19360b5b: removed 11 log segments from log reader
I20260812 06:19:34.290032  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000014 (ops 67-70)
I20260812 06:19:34.290088  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000015 (ops 71-75)
I20260812 06:19:34.290143  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000016 (ops 76-80)
I20260812 06:19:34.290184  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000017 (ops 81-85)
I20260812 06:19:34.290225  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000018 (ops 86-90)
I20260812 06:19:34.290264  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000019 (ops 91-94)
I20260812 06:19:34.290323  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000020 (ops 95-99)
I20260812 06:19:34.290380  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000021 (ops 100-104)
I20260812 06:19:34.290426  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000022 (ops 105-109)
I20260812 06:19:34.290498  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000023 (ops 110-114)
I20260812 06:19:34.290565  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000024 (ops 115-119)
I20260812 06:19:34.316213  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: LogGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:34.316606  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b): 462 bytes on disk
I20260812 06:19:34.317024  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.317600  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=7.149875
I20260812 06:19:34.346405  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.029s	user 0.015s	sys 0.011s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":12713,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:34.346891  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling LogGCOp(dbea16c462074c14b15b7cca19360b5b): free 12017983 bytes of WAL
I20260812 06:19:34.347108  8641 log_reader.cc:385] T dbea16c462074c14b15b7cca19360b5b: removed 1 log segments from log reader
I20260812 06:19:34.347157  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000025 (ops 120-124)
I20260812 06:19:34.349675  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: LogGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:34.349993  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:34.362244  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.012s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.362757  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:34.580111  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.217s	user 0.139s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":642,"lbm_read_time_us":16237,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40794,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:34.581228  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:34.635347  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.054s	user 0.042s	sys 0.007s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23558,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.635823  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=3.181125
I20260812 06:19:34.654068  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6751,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:34.654500  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:34.663976  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3721,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.664456  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:34.834537  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.170s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1379,"lbm_read_time_us":11569,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32942,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":3000}
I20260812 06:19:34.836198  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:34.887372  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.051s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.887918  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:34.901858  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.902613  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:35.073638  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.171s	user 0.123s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":917,"lbm_read_time_us":12731,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29871,"lbm_writes_lt_1ms":543,"mutex_wait_us":392,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:35.074383  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:35.138864  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.064s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21247,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.139339  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:35.149813  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.150648  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:35.325297  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.174s	user 0.127s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":11494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31337,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:35.325984  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:35.385634  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.059s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18536,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.386271  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:35.397692  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.011s	user 0.000s	sys 0.006s Metrics: {"bytes_written":1353981,"delete_count":0,"lbm_write_time_us":2388,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:19:35.398273  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.196750
I20260812 06:19:35.407125  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3341,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:19:35.407778  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:35.609935  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.202s	user 0.134s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774717,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":144,"lbm_read_time_us":14718,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31052,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:19:35.610530  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=14.095187
I20260812 06:19:35.670053  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.059s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18524,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.670655  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:35.681289  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.681798  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushMRSOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:35.722885  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushMRSOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1443,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:35.723721  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling LogGCOp(dbea16c462074c14b15b7cca19360b5b): free 112239541 bytes of WAL
I20260812 06:19:35.724045  8641 log_reader.cc:385] T dbea16c462074c14b15b7cca19360b5b: removed 11 log segments from log reader
I20260812 06:19:35.724167  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000026 (ops 125-129)
I20260812 06:19:35.724224  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000027 (ops 130-134)
I20260812 06:19:35.724277  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000028 (ops 135-139)
I20260812 06:19:35.724321  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000029 (ops 140-144)
I20260812 06:19:35.724360  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000030 (ops 145-148)
I20260812 06:19:35.724399  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000031 (ops 149-153)
I20260812 06:19:35.724440  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000032 (ops 154-158)
I20260812 06:19:35.724478  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000033 (ops 159-163)
I20260812 06:19:35.724516  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000034 (ops 164-168)
I20260812 06:19:35.724555  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000035 (ops 169-173)
I20260812 06:19:35.724592  8641 log.cc:1079] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/dbea16c462074c14b15b7cca19360b5b/wal-000000036 (ops 174-178)
I20260812 06:19:35.751099  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: LogGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:35.752313  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:35.777081  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.025s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.777705  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:35.792341  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.014s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.792884  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b): 447 bytes on disk
I20260812 06:19:35.793565  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: UndoDeltaBlockGCOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.794229  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:36.020704  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.226s	user 0.173s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":408,"lbm_read_time_us":15851,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40310,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21504,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:19:36.021499  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=15.087375
I20260812 06:19:36.064095  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.042s	user 0.033s	sys 0.004s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":17395,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:36.064657  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:36.087733  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5534,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.088275  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=2.188937
I20260812 06:19:36.099135  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.099706  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b): perf score=1.000000
I20260812 06:19:36.229823  8526 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.958s	user 1.801s	sys 0.160s
I20260812 06:19:36.271507  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: MajorDeltaCompactionOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.171s	user 0.134s	sys 0.035s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":13358,"lbm_reads_lt_1ms":669,"lbm_write_time_us":36481,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:19:36.272004  8707 maintenance_manager.cc:419] P 43d0f2eb73e944d397e4368be19c9e9f: Scheduling FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b): perf score=10.126437
I20260812 06:19:36.297250  8526 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.003s	sys 0.000s
I20260812 06:19:36.297904  8526 tablet_server.cc:179] TabletServer@127.8.83.129:0 shutting down...
I20260812 06:19:36.313644  8641 maintenance_manager.cc:643] P 43d0f2eb73e944d397e4368be19c9e9f: FlushDeltaMemStoresOp(dbea16c462074c14b15b7cca19360b5b) complete. Timing: real 0.041s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18002,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.315549  8526 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:36.315944  8526 tablet_replica.cc:333] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f: stopping tablet replica
I20260812 06:19:36.316236  8526 raft_consensus.cc:2243] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.316511  8526 raft_consensus.cc:2272] T dbea16c462074c14b15b7cca19360b5b P 43d0f2eb73e944d397e4368be19c9e9f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.332736  8526 tablet_server.cc:196] TabletServer@127.8.83.129:0 shutdown complete.
I20260812 06:19:36.339684  8526 master.cc:562] Master@127.8.83.190:34539 shutting down...
I20260812 06:19:36.344409  8526 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.344585  8526 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.344683  8526 tablet_replica.cc:333] T 00000000000000000000000000000000 P 33000d8ecc434a2dbd79402ea2f47132: stopping tablet replica
I20260812 06:19:36.357038  8526 master.cc:584] Master@127.8.83.190:34539 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5466 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:36.456745  8526 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.83.190:35493
I20260812 06:19:36.457113  8526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:36.459164  8526 server_base.cc:1061] running on GCE node
W20260812 06:19:36.459120  8743 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.459120  8742 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.459148  8745 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.459657  8526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.459719  8526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.459744  8526 hybrid_clock.cc:648] HybridClock initialized: now 1786515576459743 us; error 0 us; skew 500 ppm
I20260812 06:19:36.460691  8526 webserver.cc:533] Webserver started at http://127.8.83.190:45465/ using document root <none> and password file <none>
I20260812 06:19:36.460886  8526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.460952  8526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.461061  8526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.461477  8526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/master-0-root/instance:
uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-1jjb"
I20260812 06:19:36.462996  8526 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:36.463918  8750 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.464218  8526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:36.464313  8526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/master-0-root
uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-1jjb"
I20260812 06:19:36.464416  8526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.487409  8526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.487850  8526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.491721  8526 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.190:35493
I20260812 06:19:36.503541  8812 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.190:35493 every 8 connection(s)
I20260812 06:19:36.511013  8813 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.513203  8813 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc: Bootstrap starting.
I20260812 06:19:36.514030  8813 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.515141  8813 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc: No bootstrap required, opened a new log
I20260812 06:19:36.515599  8813 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER }
I20260812 06:19:36.515712  8813 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.515756  8813 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c7d5f8975f84715bc4f9aa62cb15bdc, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.515957  8813 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [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: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER }
I20260812 06:19:36.516068  8813 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.516141  8813 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.516201  8813 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.516885  8813 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER }
I20260812 06:19:36.517040  8813 leader_election.cc:304] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [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: 4c7d5f8975f84715bc4f9aa62cb15bdc; no voters: 
I20260812 06:19:36.517256  8813 leader_election.cc:290] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.517392  8816 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.517675  8816 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 1 LEADER]: Becoming Leader. State: Replica: 4c7d5f8975f84715bc4f9aa62cb15bdc, State: Running, Role: LEADER
I20260812 06:19:36.517764  8813 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:36.517819  8816 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [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: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER }
I20260812 06:19:36.518286  8817 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER } }
I20260812 06:19:36.518399  8817 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.518301  8818 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4c7d5f8975f84715bc4f9aa62cb15bdc. Latest consensus state: current_term: 1 leader_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c7d5f8975f84715bc4f9aa62cb15bdc" member_type: VOTER } }
I20260812 06:19:36.518538  8818 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.519011  8822 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:36.519722  8822 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:36.520004  8526 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:36.521622  8822 catalog_manager.cc:1383] Generated new cluster ID: 72665a4913da48d5a662a2581a6b829d
I20260812 06:19:36.521678  8822 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:36.534530  8822 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:36.535053  8822 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:36.538914  8822 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc: Generated new TSK 0
I20260812 06:19:36.539065  8822 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:36.552538  8526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.554883  8837 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.554913  8834 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.554930  8835 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.555099  8526 server_base.cc:1061] running on GCE node
I20260812 06:19:36.555349  8526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.555426  8526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.555449  8526 hybrid_clock.cc:648] HybridClock initialized: now 1786515576555448 us; error 0 us; skew 500 ppm
I20260812 06:19:36.556399  8526 webserver.cc:533] Webserver started at http://127.8.83.129:37351/ using document root <none> and password file <none>
I20260812 06:19:36.556548  8526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.556598  8526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.556658  8526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.557036  8526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/instance:
uuid: "6f0abbac51f74e67b5269586b93ea8ea"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-1jjb"
I20260812 06:19:36.558531  8526 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:36.559399  8845 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.559643  8526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:36.559707  8526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root
uuid: "6f0abbac51f74e67b5269586b93ea8ea"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-1jjb"
I20260812 06:19:36.559815  8526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.576539  8526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.576975  8526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.577298  8526 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:36.577796  8526 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:36.577867  8526 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.577932  8526 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:36.577986  8526 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.582456  8526 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.129:41877
I20260812 06:19:36.582530  8916 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.129:41877 every 8 connection(s)
I20260812 06:19:36.592388  8917 heartbeater.cc:344] Connected to a master server at 127.8.83.190:35493
I20260812 06:19:36.592545  8917 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:36.592815  8917 heartbeater.cc:507] Master 127.8.83.190:35493 requested a full tablet report, sending...
I20260812 06:19:36.593595  8772 ts_manager.cc:194] Registered new tserver with Master: 6f0abbac51f74e67b5269586b93ea8ea (127.8.83.129:41877)
I20260812 06:19:36.594188  8526 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011239031s
I20260812 06:19:36.594446  8772 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40986
I20260812 06:19:36.601238  8772 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41002:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:36.610165  8879 tablet_service.cc:1511] Processing CreateTablet for tablet cec3ea31ca52410a9a8368f5d5ece0a3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=63afa2845f234345b777e613adced0e0]), partition=
I20260812 06:19:36.610478  8879 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cec3ea31ca52410a9a8368f5d5ece0a3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.612811  8931 tablet_bootstrap.cc:492] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Bootstrap starting.
I20260812 06:19:36.613844  8931 tablet_bootstrap.cc:654] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.614939  8931 tablet_bootstrap.cc:492] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: No bootstrap required, opened a new log
I20260812 06:19:36.615049  8931 ts_tablet_manager.cc:1403] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.615540  8931 raft_consensus.cc:359] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f0abbac51f74e67b5269586b93ea8ea" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 41877 } }
I20260812 06:19:36.615628  8931 raft_consensus.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.615692  8931 raft_consensus.cc:740] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6f0abbac51f74e67b5269586b93ea8ea, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.615856  8931 consensus_queue.cc:260] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [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: "6f0abbac51f74e67b5269586b93ea8ea" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 41877 } }
I20260812 06:19:36.615936  8931 raft_consensus.cc:399] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.616063  8931 raft_consensus.cc:493] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.616154  8931 raft_consensus.cc:3060] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.616992  8931 raft_consensus.cc:515] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f0abbac51f74e67b5269586b93ea8ea" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 41877 } }
I20260812 06:19:36.617117  8931 leader_election.cc:304] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [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: 6f0abbac51f74e67b5269586b93ea8ea; no voters: 
I20260812 06:19:36.617278  8931 leader_election.cc:290] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.617417  8933 raft_consensus.cc:2804] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.617647  8917 heartbeater.cc:499] Master 127.8.83.190:35493 was elected leader, sending a full tablet report...
I20260812 06:19:36.617622  8931 ts_tablet_manager.cc:1434] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:36.617626  8933 raft_consensus.cc:697] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 1 LEADER]: Becoming Leader. State: Replica: 6f0abbac51f74e67b5269586b93ea8ea, State: Running, Role: LEADER
I20260812 06:19:36.617836  8933 consensus_queue.cc:237] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [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: "6f0abbac51f74e67b5269586b93ea8ea" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 41877 } }
I20260812 06:19:36.619280  8772 catalog_manager.cc:5719] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea reported cstate change: term changed from 0 to 1, leader changed from <none> to 6f0abbac51f74e67b5269586b93ea8ea (127.8.83.129). New cstate: current_term: 1 leader_uuid: "6f0abbac51f74e67b5269586b93ea8ea" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f0abbac51f74e67b5269586b93ea8ea" member_type: VOTER last_known_addr { host: "127.8.83.129" port: 41877 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:36.680408  8526 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.009s	sys 0.013s
I20260812 06:19:36.833575  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=19.054940
I20260812 06:19:36.985795  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.152s	user 0.099s	sys 0.047s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":909,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40090,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:36.986446  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): free 20743880 bytes of WAL
I20260812 06:19:36.986678  8850 log_reader.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3: removed 2 log segments from log reader
I20260812 06:19:36.986719  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000001 (ops 1-6)
I20260812 06:19:36.986748  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000002 (ops 7-11)
I20260812 06:19:36.991163  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:36.991497  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:37.007973  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.009024  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): 16411393 bytes on disk
I20260812 06:19:37.009523  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.009943  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:37.141523  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.131s	user 0.109s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":901,"lbm_read_time_us":9415,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24119,"lbm_writes_lt_1ms":443,"mutex_wait_us":114,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"thread_start_us":355,"threads_started":5,"update_count":2000}
I20260812 06:19:37.142208  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=11.118625
I20260812 06:19:37.178498  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.036s	user 0.016s	sys 0.018s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15762,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.178998  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:37.194065  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5287,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.194598  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:37.327672  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.133s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":893,"lbm_read_time_us":9944,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24945,"lbm_writes_lt_1ms":443,"mutex_wait_us":334,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:19:37.328452  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:37.377302  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.049s	user 0.019s	sys 0.026s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14571,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.377955  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:37.390107  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.390646  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:37.555858  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.165s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":386,"lbm_read_time_us":13757,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25829,"lbm_writes_lt_1ms":443,"mutex_wait_us":97,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:19:37.556638  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:37.605757  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.049s	user 0.031s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.606297  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:37.620219  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.620688  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:37.751703  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.131s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":10698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24636,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2000}
I20260812 06:19:37.752632  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:37.793097  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17436,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.793661  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:37.809693  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.810410  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:37.948271  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.138s	user 0.101s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":10740,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23059,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:37.949035  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:37.997370  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.048s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16927,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.997826  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:38.008343  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.008944  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:38.151520  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.142s	user 0.094s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":131,"lbm_read_time_us":10197,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26305,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:38.152285  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:38.208137  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.056s	user 0.036s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.208894  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:38.224783  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.225399  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:38.255836  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1217,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1551,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:38.256461  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): free 108535449 bytes of WAL
I20260812 06:19:38.256697  8850 log_reader.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3: removed 11 log segments from log reader
I20260812 06:19:38.256740  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000003 (ops 12-16)
I20260812 06:19:38.256793  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000004 (ops 17-21)
I20260812 06:19:38.256837  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000005 (ops 22-26)
I20260812 06:19:38.256888  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000006 (ops 27-31)
I20260812 06:19:38.256925  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000007 (ops 32-36)
I20260812 06:19:38.256986  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000008 (ops 37-40)
I20260812 06:19:38.257027  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000009 (ops 41-45)
I20260812 06:19:38.257067  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000010 (ops 46-50)
I20260812 06:19:38.257107  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000011 (ops 51-54)
I20260812 06:19:38.257146  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000012 (ops 55-59)
I20260812 06:19:38.257185  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000013 (ops 60-64)
I20260812 06:19:38.283169  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:38.283617  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): 462 bytes on disk
I20260812 06:19:38.284241  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.284871  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=3.181125
I20260812 06:19:38.299177  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.014s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4487,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:38.299645  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): free 12017927 bytes of WAL
I20260812 06:19:38.299853  8850 log_reader.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3: removed 1 log segments from log reader
I20260812 06:19:38.299942  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000014 (ops 65-69)
I20260812 06:19:38.302502  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:38.302815  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:38.313716  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3638,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:38.314352  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:38.522532  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.208s	user 0.132s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":335,"lbm_read_time_us":13994,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34464,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":128,"threads_started":1,"update_count":3000}
I20260812 06:19:38.523343  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=16.079562
I20260812 06:19:38.591771  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.068s	user 0.034s	sys 0.015s Metrics: {"bytes_written":17927797,"delete_count":0,"lbm_write_time_us":23390,"lbm_writes_lt_1ms":440,"reinsert_count":0,"update_count":2185}
I20260812 06:19:38.592381  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=5.165500
I20260812 06:19:38.612382  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":6687189,"delete_count":0,"lbm_write_time_us":8365,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:38.612864  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:38.820869  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.208s	user 0.123s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877108,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":859,"lbm_read_time_us":13907,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34123,"lbm_writes_lt_1ms":643,"mutex_wait_us":313,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":3000}
I20260812 06:19:38.821678  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=18.063937
I20260812 06:19:38.873543  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.052s	user 0.039s	sys 0.011s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22547,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:38.874138  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:39.057773  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.183s	user 0.106s	sys 0.076s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":147,"lbm_read_time_us":12912,"lbm_reads_lt_1ms":563,"lbm_write_time_us":31657,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:39.058432  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:39.121692  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.063s	user 0.022s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.122287  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:39.132922  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.133361  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:39.317548  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.184s	user 0.129s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":608,"lbm_read_time_us":12819,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32975,"lbm_writes_lt_1ms":543,"mutex_wait_us":375,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:39.318265  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=11.118625
I20260812 06:19:39.358999  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17610,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.359802  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:39.372454  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4416,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.372972  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:39.546538  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.173s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":581,"lbm_read_time_us":10111,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25695,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.547363  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:39.595724  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.048s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.596354  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:39.609656  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.610181  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:39.757644  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.147s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":653,"lbm_read_time_us":11244,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29715,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:19:39.758424  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=10.126437
I20260812 06:19:39.804564  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.046s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.805089  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:39.816571  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.817097  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:39.846055  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.029s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1229,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1426,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:39.846808  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): free 121006446 bytes of WAL
I20260812 06:19:39.847065  8850 log_reader.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3: removed 12 log segments from log reader
I20260812 06:19:39.847134  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000015 (ops 70-74)
I20260812 06:19:39.847187  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000016 (ops 75-79)
I20260812 06:19:39.847245  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000017 (ops 80-84)
I20260812 06:19:39.847289  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000018 (ops 85-89)
I20260812 06:19:39.847328  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000019 (ops 90-94)
I20260812 06:19:39.847368  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000020 (ops 95-99)
I20260812 06:19:39.847409  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000021 (ops 100-104)
I20260812 06:19:39.847447  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000022 (ops 105-109)
I20260812 06:19:39.847486  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000023 (ops 110-114)
I20260812 06:19:39.847532  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000024 (ops 115-118)
I20260812 06:19:39.847572  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000025 (ops 119-123)
I20260812 06:19:39.847609  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000026 (ops 124-128)
I20260812 06:19:39.875007  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:39.875536  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): 473 bytes on disk
I20260812 06:19:39.875957  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: UndoDeltaBlockGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.876480  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=3.181125
I20260812 06:19:39.887982  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.888458  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:39.897950  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3631,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.898414  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:40.073330  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.175s	user 0.140s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":533,"lbm_read_time_us":14428,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36306,"lbm_writes_lt_1ms":643,"mutex_wait_us":79,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:40.074085  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:40.127312  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.051s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.127836  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:40.139304  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.139787  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:40.309512  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.170s	user 0.130s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":11091,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34627,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:19:40.310230  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:40.378508  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.068s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":30658,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.379055  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:40.394563  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.395262  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:40.575912  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.180s	user 0.112s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":13782,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29213,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:40.576670  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:40.633635  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.057s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24808,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.634102  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:40.780401  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.146s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":144,"lbm_read_time_us":9540,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22698,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:40.781122  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:40.828567  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.047s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.829118  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:40.853982  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.025s	user 0.008s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.854743  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:41.042090  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.187s	user 0.131s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":13370,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30959,"lbm_writes_lt_1ms":543,"mutex_wait_us":344,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.042683  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:41.094138  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.051s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22836,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.094904  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:41.112435  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.112897  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:41.254761  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.142s	user 0.089s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":849,"lbm_read_time_us":8875,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26998,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:41.255327  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=14.095187
I20260812 06:19:41.307406  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.052s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.307961  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=2.188937
I20260812 06:19:41.319671  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.320425  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:41.351392  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushMRSOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1399,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1481,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:41.352167  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3): free 127961371 bytes of WAL
I20260812 06:19:41.352407  8850 log_reader.cc:385] T cec3ea31ca52410a9a8368f5d5ece0a3: removed 12 log segments from log reader
I20260812 06:19:41.352449  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000027 (ops 129-133)
I20260812 06:19:41.352478  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000028 (ops 134-138)
I20260812 06:19:41.352540  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000029 (ops 139-143)
I20260812 06:19:41.352582  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000030 (ops 144-148)
I20260812 06:19:41.352623  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000031 (ops 149-153)
I20260812 06:19:41.352667  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000032 (ops 154-158)
I20260812 06:19:41.352708  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000033 (ops 159-163)
I20260812 06:19:41.352749  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000034 (ops 164-168)
I20260812 06:19:41.352787  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000035 (ops 169-173)
I20260812 06:19:41.352826  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000036 (ops 174-178)
I20260812 06:19:41.352865  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000037 (ops 179-183)
I20260812 06:19:41.352914  8850 log.cc:1079] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: Deleting log segment in path: /tmp/dist-test-taskkAQYAi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515570979226-8526-0/minicluster-data/ts-0-root/wals/cec3ea31ca52410a9a8368f5d5ece0a3/wal-000000038 (ops 184-188)
I20260812 06:19:41.383013  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: LogGCOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.031s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:19:41.383570  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=5.165500
I20260812 06:19:41.413548  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.030s	user 0.017s	sys 0.011s Metrics: {"bytes_written":7097425,"delete_count":0,"lbm_write_time_us":7103,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:19:41.414111  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=1.000000
I20260812 06:19:41.584686  8526 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.904s	user 1.824s	sys 0.135s
I20260812 06:19:41.642902  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: MajorDeltaCompactionOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.229s	user 0.138s	sys 0.087s Metrics: {"cfile_cache_miss":706,"cfile_cache_miss_bytes":31871980,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":16360,"lbm_reads_lt_1ms":738,"lbm_write_time_us":36158,"lbm_writes_lt_1ms":716,"peak_mem_usage":83739947,"reinsert_count":0,"update_count":3365}
I20260812 06:19:41.643505  8918 maintenance_manager.cc:419] P 6f0abbac51f74e67b5269586b93ea8ea: Scheduling FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3): perf score=15.087375
I20260812 06:19:41.670876  8526 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.002s	sys 0.000s
I20260812 06:19:41.671485  8526 tablet_server.cc:179] TabletServer@127.8.83.129:0 shutting down...
I20260812 06:19:41.705161  8850 maintenance_manager.cc:643] P 6f0abbac51f74e67b5269586b93ea8ea: FlushDeltaMemStoresOp(cec3ea31ca52410a9a8368f5d5ece0a3) complete. Timing: real 0.061s	user 0.029s	sys 0.031s Metrics: {"bytes_written":17517554,"delete_count":0,"lbm_write_time_us":22971,"lbm_writes_lt_1ms":430,"reinsert_count":0,"update_count":2135}
I20260812 06:19:41.705825  8526 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:41.706125  8526 tablet_replica.cc:333] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea: stopping tablet replica
I20260812 06:19:41.706300  8526 raft_consensus.cc:2243] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.706455  8526 raft_consensus.cc:2272] T cec3ea31ca52410a9a8368f5d5ece0a3 P 6f0abbac51f74e67b5269586b93ea8ea [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.710347  8526 tablet_server.cc:196] TabletServer@127.8.83.129:0 shutdown complete.
I20260812 06:19:41.713124  8526 master.cc:562] Master@127.8.83.190:35493 shutting down...
I20260812 06:19:41.716540  8526 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.716666  8526 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.716713  8526 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4c7d5f8975f84715bc4f9aa62cb15bdc: stopping tablet replica
I20260812 06:19:41.728782  8526 master.cc:584] Master@127.8.83.190:35493 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5364 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10832 ms total)

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