[==========] 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:46.636871 18046 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.159.190:42725
I20260812 06:19:46.637838 18046 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:46.638411 18046 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.644541 18055 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:46.644616 18046 server_base.cc:1061] running on GCE node
W20260812 06:19:46.644538 18054 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:46.644735 18058 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:46.645275 18046 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.645382 18046 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:46.645429 18046 hybrid_clock.cc:648] HybridClock initialized: now 1786515586645427 us; error 0 us; skew 500 ppm
I20260812 06:19:46.647061 18046 webserver.cc:533] Webserver started at http://127.17.159.190:33797/ using document root <none> and password file <none>
I20260812 06:19:46.647552 18046 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.647607 18046 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.647866 18046 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.649415 18046 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/master-0-root/instance:
uuid: "1f31435aac8446f88a606554bb0343da"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-39l8"
I20260812 06:19:46.652715 18046 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:46.654603 18065 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:46.655560 18046 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:46.655689 18046 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/master-0-root
uuid: "1f31435aac8446f88a606554bb0343da"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-39l8"
I20260812 06:19:46.655778 18046 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-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:46.676051 18046 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.676656 18046 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:46.676793 18046 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.684345 18046 rpc_server.cc:307] RPC server started. Bound to: 127.17.159.190:42725
I20260812 06:19:46.684358 18156 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.159.190:42725 every 8 connection(s)
I20260812 06:19:46.686549 18157 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:46.691818 18157 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: Bootstrap starting.
I20260812 06:19:46.694082 18157 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.694981 18157 log.cc:826] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:46.696496 18157 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: No bootstrap required, opened a new log
I20260812 06:19:46.699112 18157 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f31435aac8446f88a606554bb0343da" member_type: VOTER }
I20260812 06:19:46.699272 18157 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.699313 18157 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1f31435aac8446f88a606554bb0343da, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.699879 18157 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [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: "1f31435aac8446f88a606554bb0343da" member_type: VOTER }
I20260812 06:19:46.700014 18157 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.700059 18157 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.700150 18157 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.700848 18157 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f31435aac8446f88a606554bb0343da" member_type: VOTER }
I20260812 06:19:46.701223 18157 leader_election.cc:304] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [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: 1f31435aac8446f88a606554bb0343da; no voters: 
I20260812 06:19:46.701460 18157 leader_election.cc:290] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.701604 18167 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.701867 18167 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 1 LEADER]: Becoming Leader. State: Replica: 1f31435aac8446f88a606554bb0343da, State: Running, Role: LEADER
I20260812 06:19:46.702363 18167 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [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: "1f31435aac8446f88a606554bb0343da" member_type: VOTER }
I20260812 06:19:46.702430 18157 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:46.704268 18168 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1f31435aac8446f88a606554bb0343da" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f31435aac8446f88a606554bb0343da" member_type: VOTER } }
I20260812 06:19:46.704376 18168 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.704331 18169 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1f31435aac8446f88a606554bb0343da. Latest consensus state: current_term: 1 leader_uuid: "1f31435aac8446f88a606554bb0343da" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f31435aac8446f88a606554bb0343da" member_type: VOTER } }
I20260812 06:19:46.704432 18169 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.704799 18186 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:46.704887 18046 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:46.707021 18186 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:46.711359 18186 catalog_manager.cc:1383] Generated new cluster ID: c3a716c578cd4776a886c040c7e15827
I20260812 06:19:46.711421 18186 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:46.722661 18186 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:46.723507 18186 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.735391 18186 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: Generated new TSK 0
I20260812 06:19:46.735997 18186 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.737264 18046 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.739799 18198 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:46.739861 18202 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:46.739892 18200 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:46.740144 18046 server_base.cc:1061] running on GCE node
I20260812 06:19:46.740314 18046 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.740358 18046 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:46.740384 18046 hybrid_clock.cc:648] HybridClock initialized: now 1786515586740385 us; error 0 us; skew 500 ppm
I20260812 06:19:46.741364 18046 webserver.cc:533] Webserver started at http://127.17.159.129:34357/ using document root <none> and password file <none>
I20260812 06:19:46.741540 18046 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.741596 18046 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.741688 18046 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.742076 18046 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/instance:
uuid: "46d7747f71dd4dd0901778222b5771ba"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-39l8"
I20260812 06:19:46.743731 18046 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:46.744781 18207 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:46.745026 18046 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:46.745100 18046 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root
uuid: "46d7747f71dd4dd0901778222b5771ba"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-39l8"
I20260812 06:19:46.745189 18046 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-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:46.778960 18046 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.779456 18046 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.779982 18046 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.780923 18046 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.780977 18046 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.781047 18046 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.781090 18046 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.788076 18046 rpc_server.cc:307] RPC server started. Bound to: 127.17.159.129:34009
I20260812 06:19:46.788125 18304 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.159.129:34009 every 8 connection(s)
I20260812 06:19:46.798164 18305 heartbeater.cc:344] Connected to a master server at 127.17.159.190:42725
I20260812 06:19:46.798408 18305 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.798897 18305 heartbeater.cc:507] Master 127.17.159.190:42725 requested a full tablet report, sending...
I20260812 06:19:46.800382 18095 ts_manager.cc:194] Registered new tserver with Master: 46d7747f71dd4dd0901778222b5771ba (127.17.159.129:34009)
I20260812 06:19:46.801010 18046 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012277002s
I20260812 06:19:46.801898 18095 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55756
I20260812 06:19:46.814787 18095 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55766:
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:46.829412 18248 tablet_service.cc:1511] Processing CreateTablet for tablet 7758207e87024f52aa76e9922948afad (DEFAULT_TABLE table=heavy-update-compaction-test [id=505243f76a6f4f8faa32685b50fa370a]), partition=
I20260812 06:19:46.829833 18248 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7758207e87024f52aa76e9922948afad. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.832329 18324 tablet_bootstrap.cc:492] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Bootstrap starting.
I20260812 06:19:46.833194 18324 tablet_bootstrap.cc:654] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.834669 18324 tablet_bootstrap.cc:492] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: No bootstrap required, opened a new log
I20260812 06:19:46.834813 18324 ts_tablet_manager.cc:1403] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:46.835268 18324 raft_consensus.cc:359] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46d7747f71dd4dd0901778222b5771ba" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 34009 } }
I20260812 06:19:46.835371 18324 raft_consensus.cc:385] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.835393 18324 raft_consensus.cc:740] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 46d7747f71dd4dd0901778222b5771ba, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.835590 18324 consensus_queue.cc:260] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [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: "46d7747f71dd4dd0901778222b5771ba" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 34009 } }
I20260812 06:19:46.835990 18324 raft_consensus.cc:399] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.836057 18324 raft_consensus.cc:493] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.836122 18324 raft_consensus.cc:3060] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.836884 18324 raft_consensus.cc:515] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46d7747f71dd4dd0901778222b5771ba" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 34009 } }
I20260812 06:19:46.837028 18324 leader_election.cc:304] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [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: 46d7747f71dd4dd0901778222b5771ba; no voters: 
I20260812 06:19:46.837280 18324 leader_election.cc:290] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.837402 18326 raft_consensus.cc:2804] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.837601 18326 raft_consensus.cc:697] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 1 LEADER]: Becoming Leader. State: Replica: 46d7747f71dd4dd0901778222b5771ba, State: Running, Role: LEADER
I20260812 06:19:46.837752 18326 consensus_queue.cc:237] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [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: "46d7747f71dd4dd0901778222b5771ba" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 34009 } }
I20260812 06:19:46.837915 18324 ts_tablet_manager.cc:1434] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:46.838344 18305 heartbeater.cc:499] Master 127.17.159.190:42725 was elected leader, sending a full tablet report...
I20260812 06:19:46.840874 18095 catalog_manager.cc:5719] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba reported cstate change: term changed from 0 to 1, leader changed from <none> to 46d7747f71dd4dd0901778222b5771ba (127.17.159.129). New cstate: current_term: 1 leader_uuid: "46d7747f71dd4dd0901778222b5771ba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46d7747f71dd4dd0901778222b5771ba" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 34009 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.913126 18046 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.024s	sys 0.008s
I20260812 06:19:47.039604 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushMRSOp(7758207e87024f52aa76e9922948afad): perf score=15.086190
I20260812 06:19:47.198357 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushMRSOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.158s	user 0.117s	sys 0.036s Metrics: {"bytes_written":12758747,"cfile_init":1,"compiler_manager_pool.queue_time_us":205,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":818,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39846,"lbm_writes_lt_1ms":678,"mutex_wait_us":1704,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":157312,"thread_start_us":119,"threads_started":1,"update_count":1555}
I20260812 06:19:47.199599 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling LogGCOp(7758207e87024f52aa76e9922948afad): free 20743880 bytes of WAL
I20260812 06:19:47.199877 18212 log_reader.cc:385] T 7758207e87024f52aa76e9922948afad: removed 2 log segments from log reader
I20260812 06:19:47.199941 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000001 (ops 1-6)
I20260812 06:19:47.199994 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000002 (ops 7-11)
I20260812 06:19:47.205812 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: LogGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:47.206254 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.221902 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3651384,"delete_count":0,"lbm_write_time_us":4735,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:47.222342 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad): 12719216 bytes on disk
I20260812 06:19:47.222987 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.223380 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.237079 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5310,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.237583 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:47.394147 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.156s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364536,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":581,"lbm_read_time_us":10762,"lbm_reads_lt_1ms":559,"lbm_write_time_us":29390,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":305,"threads_started":5,"update_count":2450}
I20260812 06:19:47.394915 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:47.441054 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.046s	user 0.016s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16515,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.441558 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.452733 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4021,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.453161 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:47.568400 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.115s	user 0.089s	sys 0.026s 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":782,"lbm_read_time_us":7362,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24502,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:47.569144 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:47.607645 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.038s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18284,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.608137 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.619776 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.620373 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:47.728715 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.108s	user 0.082s	sys 0.026s 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":181,"lbm_read_time_us":7334,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21906,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:47.729347 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:47.775622 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.046s	user 0.024s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17802,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.776131 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.789209 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.789705 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:47.918030 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.128s	user 0.088s	sys 0.040s 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":364,"lbm_read_time_us":8351,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23157,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:19:47.918587 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:47.962613 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.044s	user 0.012s	sys 0.029s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21016,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.963137 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:47.979347 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.979862 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:48.115074 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.135s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":9304,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26438,"lbm_writes_lt_1ms":443,"mutex_wait_us":307,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2000}
I20260812 06:19:48.115901 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:48.149386 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.033s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15412,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.149989 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:48.161859 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.162318 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:48.289762 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.127s	user 0.107s	sys 0.019s 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":235,"lbm_read_time_us":9439,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22715,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:48.290666 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:48.327138 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.036s	user 0.014s	sys 0.021s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":18078,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.327708 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:48.339264 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.339701 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushMRSOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:48.367937 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushMRSOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1359,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:48.368736 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling LogGCOp(7758207e87024f52aa76e9922948afad): free 112239266 bytes of WAL
I20260812 06:19:48.368952 18212 log_reader.cc:385] T 7758207e87024f52aa76e9922948afad: removed 11 log segments from log reader
I20260812 06:19:48.368995 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000003 (ops 12-16)
I20260812 06:19:48.369024 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000004 (ops 17-21)
I20260812 06:19:48.369103 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000005 (ops 22-26)
I20260812 06:19:48.369151 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000006 (ops 27-31)
I20260812 06:19:48.369208 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000007 (ops 32-36)
I20260812 06:19:48.369237 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000008 (ops 37-40)
I20260812 06:19:48.369289 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000009 (ops 41-45)
I20260812 06:19:48.369326 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000010 (ops 46-50)
I20260812 06:19:48.369364 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000011 (ops 51-55)
I20260812 06:19:48.369392 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000012 (ops 56-60)
I20260812 06:19:48.369432 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000013 (ops 61-65)
I20260812 06:19:48.395709 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: LogGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:48.396189 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad): 447 bytes on disk
I20260812 06:19:48.396804 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.397303 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=4.173312
I20260812 06:19:48.414331 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":5702609,"delete_count":0,"lbm_write_time_us":6904,"lbm_writes_lt_1ms":142,"reinsert_count":0,"update_count":695}
I20260812 06:19:48.414880 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=1.196750
I20260812 06:19:48.425755 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3824,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:19:48.426335 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:48.587981 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.161s	user 0.130s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877307,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":964,"lbm_read_time_us":10295,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30803,"lbm_writes_lt_1ms":643,"mutex_wait_us":294,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:19:48.588452 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:48.643280 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.055s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24677,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.643793 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:48.655033 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.655609 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:48.817135 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.161s	user 0.117s	sys 0.035s 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":617,"lbm_read_time_us":10102,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31383,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:48.817782 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:48.866791 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.049s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20039,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.867228 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.012391 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.145s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":139,"lbm_read_time_us":9703,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24959,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.013178 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=11.118625
I20260812 06:19:49.046054 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.033s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14044,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.046664 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:49.071111 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.024s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.071565 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:49.081773 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.082242 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.270545 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.188s	user 0.128s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":950,"lbm_read_time_us":9358,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33354,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:49.271138 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:49.320972 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.050s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18183,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.321499 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:49.332677 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.333307 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.485433 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.152s	user 0.106s	sys 0.037s 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":276,"lbm_read_time_us":8797,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28930,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:19:49.486179 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:49.534968 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.049s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21395,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.535423 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:49.553501 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6527,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.554041 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.696977 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.143s	user 0.107s	sys 0.034s 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":174,"lbm_read_time_us":8510,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29804,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.697731 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:49.744305 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.046s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18387,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.744828 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:49.760015 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.760620 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushMRSOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.789014 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushMRSOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1157,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1485,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:49.789728 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling LogGCOp(7758207e87024f52aa76e9922948afad): free 129320563 bytes of WAL
I20260812 06:19:49.789958 18212 log_reader.cc:385] T 7758207e87024f52aa76e9922948afad: removed 13 log segments from log reader
I20260812 06:19:49.790005 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000014 (ops 66-70)
I20260812 06:19:49.790035 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000015 (ops 71-74)
I20260812 06:19:49.790104 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000016 (ops 75-79)
I20260812 06:19:49.790138 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000017 (ops 80-84)
I20260812 06:19:49.790179 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000018 (ops 85-88)
I20260812 06:19:49.790218 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000019 (ops 89-93)
I20260812 06:19:49.790262 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000020 (ops 94-98)
I20260812 06:19:49.790304 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000021 (ops 99-103)
I20260812 06:19:49.790354 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000022 (ops 104-108)
I20260812 06:19:49.790395 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000023 (ops 109-113)
I20260812 06:19:49.790433 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000024 (ops 114-118)
I20260812 06:19:49.790473 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000025 (ops 119-123)
I20260812 06:19:49.790512 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000026 (ops 124-128)
I20260812 06:19:49.819218 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: LogGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:49.819737 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=4.173312
I20260812 06:19:49.833976 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.014s	user 0.006s	sys 0.006s Metrics: {"bytes_written":6153870,"delete_count":0,"lbm_write_time_us":6044,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:19:49.834375 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad): 482 bytes on disk
I20260812 06:19:49.834806 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.835280 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:49.853665 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":2051402,"delete_count":0,"lbm_write_time_us":3009,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:19:49.854135 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:50.079108 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.225s	user 0.162s	sys 0.057s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979702,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":369,"lbm_read_time_us":14134,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39950,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":52864,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:50.079866 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=18.063937
I20260812 06:19:50.143190 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.063s	user 0.042s	sys 0.021s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27165,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.143901 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:50.158161 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.014s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.158752 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:50.355108 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.196s	user 0.146s	sys 0.049s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":15014,"lbm_reads_lt_1ms":668,"lbm_write_time_us":36623,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:50.355788 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=14.095187
I20260812 06:19:50.412758 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.057s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.413305 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:50.437078 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.437484 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:50.447674 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.448079 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:50.643607 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.195s	user 0.141s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":161,"lbm_read_time_us":13527,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33974,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:19:50.644378 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=15.087375
I20260812 06:19:50.718367 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.074s	user 0.029s	sys 0.033s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":30425,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:50.718956 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=6.157687
I20260812 06:19:50.739272 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8065,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:50.739818 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:50.928769 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.189s	user 0.134s	sys 0.053s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":450,"lbm_read_time_us":13069,"lbm_reads_lt_1ms":668,"lbm_write_time_us":36275,"lbm_writes_lt_1ms":643,"mutex_wait_us":90,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":39552,"update_count":3000}
I20260812 06:19:50.930277 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=16.079562
I20260812 06:19:50.983510 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.053s	user 0.033s	sys 0.015s Metrics: {"bytes_written":17722674,"delete_count":0,"lbm_write_time_us":22370,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:19:50.984071 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:50.994472 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3120,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:50.994956 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:51.004498 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3537,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.004923 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:51.194667 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.190s	user 0.116s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877188,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":670,"lbm_read_time_us":13435,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33142,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:19:51.195478 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=16.079562
I20260812 06:19:51.252915 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.057s	user 0.031s	sys 0.022s Metrics: {"bytes_written":17681651,"delete_count":0,"lbm_write_time_us":24458,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:19:51.253509 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:51.264359 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3552,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:51.264846 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushMRSOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:51.317145 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushMRSOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.052s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1493,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2377,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:51.317817 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling LogGCOp(7758207e87024f52aa76e9922948afad): free 132571546 bytes of WAL
I20260812 06:19:51.318043 18212 log_reader.cc:385] T 7758207e87024f52aa76e9922948afad: removed 13 log segments from log reader
I20260812 06:19:51.318087 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000027 (ops 129-132)
I20260812 06:19:51.318116 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000028 (ops 133-137)
I20260812 06:19:51.318135 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000029 (ops 138-142)
I20260812 06:19:51.318187 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000030 (ops 143-147)
I20260812 06:19:51.318243 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000031 (ops 148-152)
I20260812 06:19:51.318264 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000032 (ops 153-157)
I20260812 06:19:51.318321 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000033 (ops 158-162)
I20260812 06:19:51.318383 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000034 (ops 163-167)
I20260812 06:19:51.318424 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000035 (ops 168-172)
I20260812 06:19:51.318467 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000036 (ops 173-177)
I20260812 06:19:51.318508 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000037 (ops 178-182)
I20260812 06:19:51.318547 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000038 (ops 183-186)
I20260812 06:19:51.318586 18212 log.cc:1079] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/7758207e87024f52aa76e9922948afad/wal-000000039 (ops 187-191)
I20260812 06:19:51.347810 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: LogGCOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:51.348526 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=7.149875
I20260812 06:19:51.368076 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.019s	user 0.004s	sys 0.014s Metrics: {"bytes_written":8410199,"delete_count":0,"lbm_write_time_us":8662,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:19:51.368510 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad): 492 bytes on disk
I20260812 06:19:51.368927 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: UndoDeltaBlockGCOp(7758207e87024f52aa76e9922948afad) 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:51.369445 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=2.188937
I20260812 06:19:51.385591 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:19:51.386089 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad): perf score=1.000000
I20260812 06:19:51.513381 18046 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.600s	user 1.715s	sys 0.118s
I20260812 06:19:51.620751 18046 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.002s	sys 0.000s
I20260812 06:19:51.620962 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: MajorDeltaCompactionOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.235s	user 0.187s	sys 0.048s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082130,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":806,"lbm_read_time_us":17374,"lbm_reads_lt_1ms":862,"lbm_write_time_us":42410,"lbm_writes_lt_1ms":843,"mutex_wait_us":44,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":75,"threads_started":1,"update_count":4000}
I20260812 06:19:51.621797 18046 tablet_server.cc:179] TabletServer@127.17.159.129:0 shutting down...
I20260812 06:19:51.624709 18308 maintenance_manager.cc:419] P 46d7747f71dd4dd0901778222b5771ba: Scheduling FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad): perf score=10.126437
I20260812 06:19:51.669803 18212 maintenance_manager.cc:643] P 46d7747f71dd4dd0901778222b5771ba: FlushDeltaMemStoresOp(7758207e87024f52aa76e9922948afad) complete. Timing: real 0.045s	user 0.024s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12832,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.670439 18046 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.670910 18046 tablet_replica.cc:333] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba: stopping tablet replica
I20260812 06:19:51.671156 18046 raft_consensus.cc:2243] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.671401 18046 raft_consensus.cc:2272] T 7758207e87024f52aa76e9922948afad P 46d7747f71dd4dd0901778222b5771ba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.686137 18046 tablet_server.cc:196] TabletServer@127.17.159.129:0 shutdown complete.
I20260812 06:19:51.695286 18046 master.cc:562] Master@127.17.159.190:42725 shutting down...
I20260812 06:19:51.699486 18046 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.699654 18046 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.699762 18046 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1f31435aac8446f88a606554bb0343da: stopping tablet replica
I20260812 06:19:51.711963 18046 master.cc:584] Master@127.17.159.190:42725 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5160 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:51.797652 18046 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.159.190:41793
I20260812 06:19:51.798059 18046 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:51.800151 18046 server_base.cc:1061] running on GCE node
W20260812 06:19:51.800184 18354 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:51.800228 18358 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:51.800379 18352 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:51.800585 18046 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.800633 18046 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:51.800649 18046 hybrid_clock.cc:648] HybridClock initialized: now 1786515591800649 us; error 0 us; skew 500 ppm
I20260812 06:19:51.801522 18046 webserver.cc:533] Webserver started at http://127.17.159.190:40779/ using document root <none> and password file <none>
I20260812 06:19:51.801695 18046 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.801766 18046 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.801851 18046 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.802300 18046 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/master-0-root/instance:
uuid: "d3cc04f7b97c4206aa547ec17c4c50e2"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-39l8"
I20260812 06:19:51.803864 18046 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:51.804777 18367 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:51.805019 18046 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:51.805094 18046 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/master-0-root
uuid: "d3cc04f7b97c4206aa547ec17c4c50e2"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-39l8"
I20260812 06:19:51.805156 18046 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-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:51.816422 18046 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.816763 18046 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.820920 18046 rpc_server.cc:307] RPC server started. Bound to: 127.17.159.190:41793
I20260812 06:19:51.821875 18440 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.159.190:41793 every 8 connection(s)
I20260812 06:19:51.822849 18441 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:51.842617 18441 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2: Bootstrap starting.
I20260812 06:19:51.843459 18441 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.844528 18441 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2: No bootstrap required, opened a new log
I20260812 06:19:51.844898 18441 raft_consensus.cc:359] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER }
I20260812 06:19:51.844985 18441 raft_consensus.cc:385] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.845007 18441 raft_consensus.cc:740] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d3cc04f7b97c4206aa547ec17c4c50e2, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.845113 18441 consensus_queue.cc:260] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [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: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER }
I20260812 06:19:51.845217 18441 raft_consensus.cc:399] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.845270 18441 raft_consensus.cc:493] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.845331 18441 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.846074 18441 raft_consensus.cc:515] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER }
I20260812 06:19:51.846254 18441 leader_election.cc:304] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [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: d3cc04f7b97c4206aa547ec17c4c50e2; no voters: 
I20260812 06:19:51.846468 18441 leader_election.cc:290] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.846622 18447 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.846899 18447 raft_consensus.cc:697] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 1 LEADER]: Becoming Leader. State: Replica: d3cc04f7b97c4206aa547ec17c4c50e2, State: Running, Role: LEADER
I20260812 06:19:51.846975 18441 sys_catalog.cc:565] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:51.847069 18447 consensus_queue.cc:237] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [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: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER }
I20260812 06:19:51.847520 18448 sys_catalog.cc:455] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER } }
I20260812 06:19:51.847538 18449 sys_catalog.cc:455] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d3cc04f7b97c4206aa547ec17c4c50e2. Latest consensus state: current_term: 1 leader_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3cc04f7b97c4206aa547ec17c4c50e2" member_type: VOTER } }
I20260812 06:19:51.847638 18448 sys_catalog.cc:458] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.847646 18449 sys_catalog.cc:458] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.847896 18455 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:51.848685 18455 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:51.848991 18046 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:51.850440 18455 catalog_manager.cc:1383] Generated new cluster ID: f4b4a0fd04ed48dba67e9b0b90a7417d
I20260812 06:19:51.850499 18455 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:51.866725 18455 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:51.867275 18455 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:51.873080 18455 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2: Generated new TSK 0
I20260812 06:19:51.873247 18455 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:51.881400 18046 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.883322 18485 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:51.883348 18483 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:51.883348 18482 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:51.883628 18046 server_base.cc:1061] running on GCE node
I20260812 06:19:51.883785 18046 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.883839 18046 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:51.883873 18046 hybrid_clock.cc:648] HybridClock initialized: now 1786515591883872 us; error 0 us; skew 500 ppm
I20260812 06:19:51.884719 18046 webserver.cc:533] Webserver started at http://127.17.159.129:40961/ using document root <none> and password file <none>
I20260812 06:19:51.884898 18046 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.884968 18046 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.885047 18046 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.885442 18046 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/instance:
uuid: "83dfeafa4e7a4608b924db7ec9d2e9df"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-39l8"
I20260812 06:19:51.887059 18046 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:51.887972 18491 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:51.888204 18046 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:51.888293 18046 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root
uuid: "83dfeafa4e7a4608b924db7ec9d2e9df"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-39l8"
I20260812 06:19:51.888378 18046 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-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:51.900565 18046 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.900956 18046 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.901283 18046 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:51.901758 18046 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:51.901819 18046 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.901897 18046 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:51.901947 18046 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.906261 18046 rpc_server.cc:307] RPC server started. Bound to: 127.17.159.129:36513
I20260812 06:19:51.906347 18590 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.159.129:36513 every 8 connection(s)
I20260812 06:19:51.914476 18592 heartbeater.cc:344] Connected to a master server at 127.17.159.190:41793
I20260812 06:19:51.914625 18592 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:51.914883 18592 heartbeater.cc:507] Master 127.17.159.190:41793 requested a full tablet report, sending...
I20260812 06:19:51.915578 18394 ts_manager.cc:194] Registered new tserver with Master: 83dfeafa4e7a4608b924db7ec9d2e9df (127.17.159.129:36513)
I20260812 06:19:51.915617 18046 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008849009s
I20260812 06:19:51.916325 18394 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34894
I20260812 06:19:51.922569 18394 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34910:
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:51.931116 18537 tablet_service.cc:1511] Processing CreateTablet for tablet f44b3041022a4f6d84a38542f04efac0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=59aa945a95924430a956e181577251f0]), partition=
I20260812 06:19:51.931407 18537 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f44b3041022a4f6d84a38542f04efac0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:51.933470 18608 tablet_bootstrap.cc:492] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Bootstrap starting.
I20260812 06:19:51.934383 18608 tablet_bootstrap.cc:654] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.935482 18608 tablet_bootstrap.cc:492] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: No bootstrap required, opened a new log
I20260812 06:19:51.935616 18608 ts_tablet_manager.cc:1403] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:51.936014 18608 raft_consensus.cc:359] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83dfeafa4e7a4608b924db7ec9d2e9df" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 36513 } }
I20260812 06:19:51.936133 18608 raft_consensus.cc:385] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.936200 18608 raft_consensus.cc:740] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 83dfeafa4e7a4608b924db7ec9d2e9df, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.936365 18608 consensus_queue.cc:260] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [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: "83dfeafa4e7a4608b924db7ec9d2e9df" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 36513 } }
I20260812 06:19:51.936494 18608 raft_consensus.cc:399] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.936559 18608 raft_consensus.cc:493] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.936615 18608 raft_consensus.cc:3060] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.937448 18608 raft_consensus.cc:515] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83dfeafa4e7a4608b924db7ec9d2e9df" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 36513 } }
I20260812 06:19:51.937574 18608 leader_election.cc:304] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [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: 83dfeafa4e7a4608b924db7ec9d2e9df; no voters: 
I20260812 06:19:51.937724 18608 leader_election.cc:290] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.937853 18610 raft_consensus.cc:2804] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.938102 18610 raft_consensus.cc:697] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 1 LEADER]: Becoming Leader. State: Replica: 83dfeafa4e7a4608b924db7ec9d2e9df, State: Running, Role: LEADER
I20260812 06:19:51.938136 18592 heartbeater.cc:499] Master 127.17.159.190:41793 was elected leader, sending a full tablet report...
I20260812 06:19:51.938254 18610 consensus_queue.cc:237] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [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: "83dfeafa4e7a4608b924db7ec9d2e9df" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 36513 } }
I20260812 06:19:51.938357 18608 ts_tablet_manager.cc:1434] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:51.939628 18394 catalog_manager.cc:5719] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df reported cstate change: term changed from 0 to 1, leader changed from <none> to 83dfeafa4e7a4608b924db7ec9d2e9df (127.17.159.129). New cstate: current_term: 1 leader_uuid: "83dfeafa4e7a4608b924db7ec9d2e9df" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83dfeafa4e7a4608b924db7ec9d2e9df" member_type: VOTER last_known_addr { host: "127.17.159.129" port: 36513 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:52.003211 18046 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.009s	sys 0.015s
I20260812 06:19:52.157238 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushMRSOp(f44b3041022a4f6d84a38542f04efac0): perf score=19.054940
I20260812 06:19:52.306157 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushMRSOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.149s	user 0.107s	sys 0.037s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":709,"drs_written":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36133,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:19:52.307066 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling LogGCOp(f44b3041022a4f6d84a38542f04efac0): free 20743831 bytes of WAL
I20260812 06:19:52.307367 18497 log_reader.cc:385] T f44b3041022a4f6d84a38542f04efac0: removed 2 log segments from log reader
I20260812 06:19:52.307439 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000001 (ops 1-6)
I20260812 06:19:52.307492 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000002 (ops 7-11)
I20260812 06:19:52.313023 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: LogGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:52.313444 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:52.336172 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5429,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.336629 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0): 16411394 bytes on disk
I20260812 06:19:52.337020 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:52.337440 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:52.347065 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.347461 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:52.518011 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.170s	user 0.104s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":949,"lbm_read_time_us":11729,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29521,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":348,"threads_started":5,"update_count":2500}
I20260812 06:19:52.518563 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:52.572252 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.053s	user 0.027s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25908,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.572698 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:52.584117 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.584688 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:52.739959 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.155s	user 0.116s	sys 0.035s 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":846,"lbm_read_time_us":10182,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30584,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:52.740499 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:52.785691 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.045s	user 0.021s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.786151 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:52.797039 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.797458 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:52.948308 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.151s	user 0.108s	sys 0.036s 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":123,"lbm_read_time_us":10263,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30569,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:19:52.949038 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:52.998317 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21699,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.998811 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:53.011032 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.011463 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:53.173481 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.162s	user 0.126s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":9060,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30054,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:19:53.174252 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:53.240029 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.066s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25432,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:53.240584 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:53.252277 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.252933 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:53.415264 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.162s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1438,"lbm_read_time_us":10969,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28303,"lbm_writes_lt_1ms":543,"mutex_wait_us":568,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:53.416023 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:53.471110 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.055s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23570,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.471691 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:53.484501 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.485000 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushMRSOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:53.516750 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushMRSOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1224,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2103,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:53.517377 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling LogGCOp(f44b3041022a4f6d84a38542f04efac0): free 124257288 bytes of WAL
I20260812 06:19:53.517581 18497 log_reader.cc:385] T f44b3041022a4f6d84a38542f04efac0: removed 12 log segments from log reader
I20260812 06:19:53.517621 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000003 (ops 12-16)
I20260812 06:19:53.517649 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000004 (ops 17-20)
I20260812 06:19:53.517712 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000005 (ops 21-25)
I20260812 06:19:53.517750 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000006 (ops 26-30)
I20260812 06:19:53.517791 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000007 (ops 31-35)
I20260812 06:19:53.517843 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000008 (ops 36-40)
I20260812 06:19:53.517899 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000009 (ops 41-45)
I20260812 06:19:53.517938 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000010 (ops 46-50)
I20260812 06:19:53.517978 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000011 (ops 51-55)
I20260812 06:19:53.518018 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000012 (ops 56-60)
I20260812 06:19:53.518056 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000013 (ops 61-65)
I20260812 06:19:53.518100 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000014 (ops 66-70)
I20260812 06:19:53.545637 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: LogGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:53.546017 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=3.181125
I20260812 06:19:53.566537 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6788,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.567039 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:53.576833 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.577301 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:53.815981 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.239s	user 0.158s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1204,"lbm_read_time_us":17373,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41226,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8064,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:19:53.816689 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0): 472 bytes on disk
I20260812 06:19:53.817162 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.817864 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=15.087375
I20260812 06:19:53.869902 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.052s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":17749,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:53.870358 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=3.181125
I20260812 06:19:53.882082 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4389830,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:19:53.882507 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:53.891736 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3572,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:53.892129 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:54.067827 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.176s	user 0.132s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":317,"lbm_read_time_us":13511,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33714,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":3000}
I20260812 06:19:54.068481 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:54.118106 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.049s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19849,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.118580 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.142416 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.024s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.142920 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.152855 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.153270 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:54.316059 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.163s	user 0.126s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":787,"lbm_read_time_us":11965,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34363,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:54.316641 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:54.363896 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.047s	user 0.018s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22189,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.364406 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.376935 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.377420 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:54.536404 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.159s	user 0.114s	sys 0.044s 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":301,"lbm_read_time_us":11496,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30385,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:54.539501 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=12.110812
I20260812 06:19:54.586378 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.047s	user 0.024s	sys 0.016s Metrics: {"bytes_written":13661280,"delete_count":0,"lbm_write_time_us":18982,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1665}
I20260812 06:19:54.587010 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.196750
I20260812 06:19:54.598404 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.011s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3013,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:54.598941 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.612073 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5088,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.612500 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:54.789363 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.177s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":152,"lbm_read_time_us":11390,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31248,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:19:54.790112 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:54.850394 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.060s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27605,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.850950 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.860872 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.861285 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushMRSOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:54.896353 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushMRSOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.035s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":1089,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1979,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:54.896960 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling LogGCOp(f44b3041022a4f6d84a38542f04efac0): free 112692381 bytes of WAL
I20260812 06:19:54.897176 18497 log_reader.cc:385] T f44b3041022a4f6d84a38542f04efac0: removed 11 log segments from log reader
I20260812 06:19:54.897220 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000015 (ops 71-75)
I20260812 06:19:54.897248 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000016 (ops 76-80)
I20260812 06:19:54.897316 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000017 (ops 81-85)
I20260812 06:19:54.897359 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000018 (ops 86-90)
I20260812 06:19:54.897399 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000019 (ops 91-95)
I20260812 06:19:54.897455 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000020 (ops 96-100)
I20260812 06:19:54.897495 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000021 (ops 101-105)
I20260812 06:19:54.897532 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000022 (ops 106-110)
I20260812 06:19:54.897571 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000023 (ops 111-115)
I20260812 06:19:54.897614 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000024 (ops 116-120)
I20260812 06:19:54.897652 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000025 (ops 121-125)
I20260812 06:19:54.922150 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: LogGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:54.922547 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.944574 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.022s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.945057 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling LogGCOp(f44b3041022a4f6d84a38542f04efac0): free 12017940 bytes of WAL
I20260812 06:19:54.945327 18497 log_reader.cc:385] T f44b3041022a4f6d84a38542f04efac0: removed 1 log segments from log reader
I20260812 06:19:54.945400 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000026 (ops 126-130)
I20260812 06:19:54.948052 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: LogGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:54.948330 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:54.959352 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.959787 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0): 462 bytes on disk
I20260812 06:19:54.960183 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0) 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:54.960758 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:55.186837 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.226s	user 0.169s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":518,"lbm_read_time_us":16561,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42487,"lbm_writes_lt_1ms":743,"mutex_wait_us":281,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":115,"threads_started":1,"update_count":3500}
I20260812 06:19:55.187552 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=18.063937
I20260812 06:19:55.245543 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.058s	user 0.036s	sys 0.019s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26409,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:55.246035 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:55.258849 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.259271 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:55.416438 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.157s	user 0.113s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":286,"lbm_read_time_us":11842,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33244,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":3000}
I20260812 06:19:55.417140 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:55.460317 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.043s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17894,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.461138 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:55.476626 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.477289 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:55.639118 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.162s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":11313,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32416,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:19:55.639638 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=12.110812
I20260812 06:19:55.683068 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.043s	user 0.035s	sys 0.008s Metrics: {"bytes_written":14276638,"delete_count":0,"lbm_write_time_us":19178,"lbm_writes_lt_1ms":351,"reinsert_count":0,"update_count":1740}
I20260812 06:19:55.683523 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:55.691715 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.008s	user 0.006s	sys 0.001s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2469,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:19:55.692129 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:55.853739 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.161s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672219,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":865,"lbm_read_time_us":8560,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26214,"lbm_writes_lt_1ms":443,"mutex_wait_us":237,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:19:55.854332 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:55.912597 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.058s	user 0.032s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24158,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.913100 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:55.934626 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.021s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.935186 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:56.130029 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.195s	user 0.107s	sys 0.081s 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":271,"lbm_read_time_us":13936,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32500,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:56.130656 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:56.185238 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.054s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20527,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.185781 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:56.201172 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.201823 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:56.382579 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.181s	user 0.126s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":11622,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28232,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:19:56.383224 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=14.095187
I20260812 06:19:56.436992 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.054s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20201,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.437637 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:56.452499 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.453176 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushMRSOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:56.493148 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushMRSOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.040s	user 0.038s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1332,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1684,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:56.493844 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling LogGCOp(f44b3041022a4f6d84a38542f04efac0): free 121006648 bytes of WAL
I20260812 06:19:56.494081 18497 log_reader.cc:385] T f44b3041022a4f6d84a38542f04efac0: removed 12 log segments from log reader
I20260812 06:19:56.494127 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000027 (ops 131-135)
I20260812 06:19:56.494155 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000028 (ops 136-140)
I20260812 06:19:56.494218 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000029 (ops 141-145)
I20260812 06:19:56.494251 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000030 (ops 146-150)
I20260812 06:19:56.494292 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000031 (ops 151-155)
I20260812 06:19:56.494329 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000032 (ops 156-160)
I20260812 06:19:56.494374 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000033 (ops 161-165)
I20260812 06:19:56.494432 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000034 (ops 166-170)
I20260812 06:19:56.494477 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000035 (ops 171-174)
I20260812 06:19:56.494526 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000036 (ops 175-179)
I20260812 06:19:56.494565 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000037 (ops 180-184)
I20260812 06:19:56.494604 18497 log.cc:1079] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: Deleting log segment in path: /tmp/dist-test-taskqTDiHw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586626797-18046-0/minicluster-data/ts-0-root/wals/f44b3041022a4f6d84a38542f04efac0/wal-000000038 (ops 185-189)
I20260812 06:19:56.522521 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: LogGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:56.522941 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0): 493 bytes on disk
I20260812 06:19:56.523483 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: UndoDeltaBlockGCOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.524075 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=3.181125
I20260812 06:19:56.542296 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.018s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4759047,"delete_count":0,"lbm_write_time_us":6025,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:19:56.542814 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=2.188937
I20260812 06:19:56.552117 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3536,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:56.552564 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0): perf score=1.000000
I20260812 06:19:56.695945 18046 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.693s	user 1.751s	sys 0.141s
I20260812 06:19:56.765661 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: MajorDeltaCompactionOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.213s	user 0.133s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":522,"lbm_read_time_us":15787,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37211,"lbm_writes_lt_1ms":743,"mutex_wait_us":56,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:19:56.769253 18594 maintenance_manager.cc:419] P 83dfeafa4e7a4608b924db7ec9d2e9df: Scheduling FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0): perf score=10.126437
I20260812 06:19:56.777495 18046 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.002s	sys 0.000s
I20260812 06:19:56.778101 18046 tablet_server.cc:179] TabletServer@127.17.159.129:0 shutting down...
I20260812 06:19:56.810667 18497 maintenance_manager.cc:643] P 83dfeafa4e7a4608b924db7ec9d2e9df: FlushDeltaMemStoresOp(f44b3041022a4f6d84a38542f04efac0) complete. Timing: real 0.041s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13837,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.811228 18046 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:56.811724 18046 tablet_replica.cc:333] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df: stopping tablet replica
I20260812 06:19:56.811869 18046 raft_consensus.cc:2243] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.812067 18046 raft_consensus.cc:2272] T f44b3041022a4f6d84a38542f04efac0 P 83dfeafa4e7a4608b924db7ec9d2e9df [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.825523 18046 tablet_server.cc:196] TabletServer@127.17.159.129:0 shutdown complete.
I20260812 06:19:56.828299 18046 master.cc:562] Master@127.17.159.190:41793 shutting down...
I20260812 06:19:56.832121 18046 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.832280 18046 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.832376 18046 tablet_replica.cc:333] T 00000000000000000000000000000000 P d3cc04f7b97c4206aa547ec17c4c50e2: stopping tablet replica
I20260812 06:19:56.844453 18046 master.cc:584] Master@127.17.159.190:41793 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5133 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10295 ms total)

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