[==========] 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:18:59.501693  2346 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.74.190:36549
I20260812 06:18:59.502983  2346 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:18:59.503670  2346 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.510812  2354 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:18:59.511013  2359 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:18:59.511049  2346 server_base.cc:1061] running on GCE node
W20260812 06:18:59.511165  2351 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:18:59.511660  2346 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.511781  2346 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:18:59.511869  2346 hybrid_clock.cc:648] HybridClock initialized: now 1786515539511865 us; error 0 us; skew 500 ppm
I20260812 06:18:59.513996  2346 webserver.cc:533] Webserver started at http://127.2.74.190:33491/ using document root <none> and password file <none>
I20260812 06:18:59.514621  2346 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.514689  2346 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.514973  2346 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.516819  2346 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/master-0-root/instance:
uuid: "64b2804780d94e33ba465e581caea9f0"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-44d2"
I20260812 06:18:59.520700  2346 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:59.522900  2368 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:18:59.523864  2346 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:59.523998  2346 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/master-0-root
uuid: "64b2804780d94e33ba465e581caea9f0"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-44d2"
I20260812 06:18:59.524107  2346 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-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:18:59.537205  2346 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.537889  2346 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:18:59.538091  2346 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.546150  2346 rpc_server.cc:307] RPC server started. Bound to: 127.2.74.190:36549
I20260812 06:18:59.546161  2447 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.74.190:36549 every 8 connection(s)
I20260812 06:18:59.548413  2448 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:18:59.553910  2448 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: Bootstrap starting.
I20260812 06:18:59.556285  2448 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.557216  2448 log.cc:826] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:59.558945  2448 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: No bootstrap required, opened a new log
I20260812 06:18:59.561764  2448 raft_consensus.cc:359] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER }
I20260812 06:18:59.561920  2448 raft_consensus.cc:385] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.562005  2448 raft_consensus.cc:740] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 64b2804780d94e33ba465e581caea9f0, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.562606  2448 consensus_queue.cc:260] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [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: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER }
I20260812 06:18:59.562747  2448 raft_consensus.cc:399] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.562835  2448 raft_consensus.cc:493] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.562997  2448 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.563791  2448 raft_consensus.cc:515] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER }
I20260812 06:18:59.564231  2448 leader_election.cc:304] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [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: 64b2804780d94e33ba465e581caea9f0; no voters: 
I20260812 06:18:59.564595  2448 leader_election.cc:290] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.564723  2455 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.565075  2455 raft_consensus.cc:697] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 1 LEADER]: Becoming Leader. State: Replica: 64b2804780d94e33ba465e581caea9f0, State: Running, Role: LEADER
I20260812 06:18:59.565490  2455 consensus_queue.cc:237] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [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: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER }
I20260812 06:18:59.565735  2448 sys_catalog.cc:565] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:59.567442  2458 sys_catalog.cc:455] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 64b2804780d94e33ba465e581caea9f0. Latest consensus state: current_term: 1 leader_uuid: "64b2804780d94e33ba465e581caea9f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER } }
I20260812 06:18:59.567492  2456 sys_catalog.cc:455] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "64b2804780d94e33ba465e581caea9f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64b2804780d94e33ba465e581caea9f0" member_type: VOTER } }
I20260812 06:18:59.567574  2458 sys_catalog.cc:458] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.567598  2456 sys_catalog.cc:458] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.568055  2346 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:59.568035  2481 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:59.570365  2481 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:59.575181  2481 catalog_manager.cc:1383] Generated new cluster ID: 717b5f6992f84b14b57967f1ff5d41f6
I20260812 06:18:59.575260  2481 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:59.590162  2481 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:59.591154  2481 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:59.609486  2481 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: Generated new TSK 0
I20260812 06:18:59.610292  2481 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:59.632897  2346 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.635900  2490 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:18:59.636053  2495 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:18:59.636255  2346 server_base.cc:1061] running on GCE node
W20260812 06:18:59.636070  2492 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:18:59.636570  2346 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.636623  2346 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:18:59.636641  2346 hybrid_clock.cc:648] HybridClock initialized: now 1786515539636641 us; error 0 us; skew 500 ppm
I20260812 06:18:59.637620  2346 webserver.cc:533] Webserver started at http://127.2.74.129:34323/ using document root <none> and password file <none>
I20260812 06:18:59.637818  2346 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.637900  2346 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.637997  2346 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.638412  2346 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/instance:
uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-44d2"
I20260812 06:18:59.640115  2346 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:59.641330  2504 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:18:59.641647  2346 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:59.641728  2346 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root
uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-44d2"
I20260812 06:18:59.641795  2346 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-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:18:59.650238  2346 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.650676  2346 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.651183  2346 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:59.652220  2346 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:59.652287  2346 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.652340  2346 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:59.652372  2346 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.659255  2600 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.74.129:46077 every 8 connection(s)
I20260812 06:18:59.659233  2346 rpc_server.cc:307] RPC server started. Bound to: 127.2.74.129:46077
I20260812 06:18:59.674027  2601 heartbeater.cc:344] Connected to a master server at 127.2.74.190:36549
I20260812 06:18:59.674311  2601 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:59.674799  2601 heartbeater.cc:507] Master 127.2.74.190:36549 requested a full tablet report, sending...
I20260812 06:18:59.676430  2398 ts_manager.cc:194] Registered new tserver with Master: c7fc93b0e2c14aa7a5bc72a4500f4710 (127.2.74.129:46077)
I20260812 06:18:59.676738  2346 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01674462s
I20260812 06:18:59.678095  2398 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53224
I20260812 06:18:59.687081  2398 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53230:
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:18:59.701182  2548 tablet_service.cc:1511] Processing CreateTablet for tablet ff3154611c8146e78a4fc05411ce2059 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b27936e572c64f79a006c5ef85facf23]), partition=
I20260812 06:18:59.701710  2548 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ff3154611c8146e78a4fc05411ce2059. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:59.704933  2620 tablet_bootstrap.cc:492] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Bootstrap starting.
I20260812 06:18:59.705862  2620 tablet_bootstrap.cc:654] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.707058  2620 tablet_bootstrap.cc:492] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: No bootstrap required, opened a new log
I20260812 06:18:59.707168  2620 ts_tablet_manager.cc:1403] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:59.707809  2620 raft_consensus.cc:359] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 46077 } }
I20260812 06:18:59.707911  2620 raft_consensus.cc:385] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.708022  2620 raft_consensus.cc:740] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c7fc93b0e2c14aa7a5bc72a4500f4710, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.708251  2620 consensus_queue.cc:260] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [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: "c7fc93b0e2c14aa7a5bc72a4500f4710" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 46077 } }
I20260812 06:18:59.708407  2620 raft_consensus.cc:399] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.708461  2620 raft_consensus.cc:493] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.708540  2620 raft_consensus.cc:3060] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.709344  2620 raft_consensus.cc:515] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 46077 } }
I20260812 06:18:59.709471  2620 leader_election.cc:304] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [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: c7fc93b0e2c14aa7a5bc72a4500f4710; no voters: 
I20260812 06:18:59.709739  2620 leader_election.cc:290] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.709842  2624 raft_consensus.cc:2804] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.710086  2624 raft_consensus.cc:697] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 1 LEADER]: Becoming Leader. State: Replica: c7fc93b0e2c14aa7a5bc72a4500f4710, State: Running, Role: LEADER
I20260812 06:18:59.710150  2620 ts_tablet_manager.cc:1434] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:18:59.710290  2624 consensus_queue.cc:237] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [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: "c7fc93b0e2c14aa7a5bc72a4500f4710" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 46077 } }
I20260812 06:18:59.710494  2601 heartbeater.cc:499] Master 127.2.74.190:36549 was elected leader, sending a full tablet report...
I20260812 06:18:59.713382  2398 catalog_manager.cc:5719] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 reported cstate change: term changed from 0 to 1, leader changed from <none> to c7fc93b0e2c14aa7a5bc72a4500f4710 (127.2.74.129). New cstate: current_term: 1 leader_uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7fc93b0e2c14aa7a5bc72a4500f4710" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 46077 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:59.785629  2346 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.022s	sys 0.009s
I20260812 06:18:59.910645  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushMRSOp(ff3154611c8146e78a4fc05411ce2059): perf score=15.086190
I20260812 06:19:00.049705  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushMRSOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.139s	user 0.110s	sys 0.028s Metrics: {"bytes_written":9025565,"cfile_init":1,"compiler_manager_pool.queue_time_us":261,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":909,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33867,"lbm_writes_lt_1ms":577,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":235904,"thread_start_us":140,"threads_started":1,"update_count":1100}
I20260812 06:19:00.050773  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling LogGCOp(ff3154611c8146e78a4fc05411ce2059): free 11976772 bytes of WAL
I20260812 06:19:00.051102  2511 log_reader.cc:385] T ff3154611c8146e78a4fc05411ce2059: removed 1 log segments from log reader
I20260812 06:19:00.051182  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000001 (ops 1-6)
I20260812 06:19:00.054600  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: LogGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:00.055219  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:00.071578  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":5126,"lbm_writes_lt_1ms":83,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":400}
I20260812 06:19:00.072114  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:00.201471  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.129s	user 0.087s	sys 0.032s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528883,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":548,"lbm_read_time_us":6339,"lbm_reads_lt_1ms":364,"lbm_write_time_us":23111,"lbm_writes_lt_1ms":343,"mutex_wait_us":60,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":356,"threads_started":5,"update_count":1500}
I20260812 06:19:00.202164  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059): 12308958 bytes on disk
I20260812 06:19:00.202850  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.203464  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:00.248611  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.045s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18442,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.249125  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:00.262595  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.263167  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:00.394302  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.131s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":9787,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22613,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:19:00.395152  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:00.439400  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.044s	user 0.013s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.440605  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:00.568724  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.128s	user 0.083s	sys 0.044s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":204,"lbm_read_time_us":8932,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18754,"lbm_writes_lt_1ms":343,"mutex_wait_us":46,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":100480,"update_count":1500}
I20260812 06:19:00.569375  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:00.618079  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.049s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.618628  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:00.633746  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.634392  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:00.772702  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.138s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2849,"lbm_read_time_us":9190,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26840,"lbm_writes_lt_1ms":443,"mutex_wait_us":1761,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:00.773485  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:00.824111  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.050s	user 0.037s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20879,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.824679  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:00.835755  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.836395  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:00.969470  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.133s	user 0.104s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":286,"lbm_read_time_us":9592,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26622,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:19:00.970057  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:01.019866  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.050s	user 0.021s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17383,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.020601  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:01.037725  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.038345  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:01.186342  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.148s	user 0.090s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":12221,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23376,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:01.186895  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:01.231024  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.044s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13832,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.231587  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:01.245101  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.245790  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:01.383715  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.138s	user 0.105s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":10625,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29067,"lbm_writes_lt_1ms":443,"mutex_wait_us":362,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:19:01.384536  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:01.427170  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.042s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18719,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.427886  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:01.448230  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.020s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.448856  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushMRSOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:01.486933  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushMRSOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.038s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":292,"dirs.run_wall_time_us":1336,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1574,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:01.487877  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=3.181125
I20260812 06:19:01.500819  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:01.501338  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling LogGCOp(ff3154611c8146e78a4fc05411ce2059): free 133477407 bytes of WAL
I20260812 06:19:01.501569  2511 log_reader.cc:385] T ff3154611c8146e78a4fc05411ce2059: removed 13 log segments from log reader
I20260812 06:19:01.501616  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000002 (ops 7-11)
I20260812 06:19:01.501643  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000003 (ops 12-16)
I20260812 06:19:01.501706  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000004 (ops 17-21)
I20260812 06:19:01.501763  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000005 (ops 22-26)
I20260812 06:19:01.501803  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000006 (ops 27-31)
I20260812 06:19:01.501844  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000007 (ops 32-36)
I20260812 06:19:01.501883  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000008 (ops 37-41)
I20260812 06:19:01.501921  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000009 (ops 42-46)
I20260812 06:19:01.501968  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000010 (ops 47-51)
I20260812 06:19:01.502008  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000011 (ops 52-56)
I20260812 06:19:01.502046  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000012 (ops 57-61)
I20260812 06:19:01.502084  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000013 (ops 62-66)
I20260812 06:19:01.502122  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000014 (ops 67-71)
I20260812 06:19:01.531778  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: LogGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:01.532299  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=3.181125
I20260812 06:19:01.543962  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4348806,"delete_count":0,"lbm_write_time_us":4541,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:19:01.544382  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:01.553889  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3409,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:01.554432  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059): 482 bytes on disk
I20260812 06:19:01.555102  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":134,"lbm_reads_lt_1ms":4}
I20260812 06:19:01.555694  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:01.762843  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.207s	user 0.168s	sys 0.035s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938888,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1522,"lbm_read_time_us":14689,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41504,"lbm_writes_lt_1ms":743,"mutex_wait_us":3480,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12032,"thread_start_us":115,"threads_started":1,"update_count":3500}
I20260812 06:19:01.763548  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=14.095187
I20260812 06:19:01.826831  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.063s	user 0.027s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24648,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.827474  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:01.845916  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.846539  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.020054  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.173s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":12892,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29557,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:19:02.020752  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:02.057376  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16061,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.057884  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:02.073055  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.073554  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.202807  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.129s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":7935,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24521,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.203485  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:02.236038  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.032s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13814,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.236676  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:02.251389  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.251914  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.395394  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.143s	user 0.091s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":7990,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30892,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:02.396198  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:02.440889  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.044s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16683,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.441443  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:02.451998  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.453053  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.586215  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.133s	user 0.084s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1273,"lbm_read_time_us":11519,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":24226,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:02.586890  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:02.642382  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.055s	user 0.021s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18842,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.643128  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:02.659621  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.660255  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.818100  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.158s	user 0.113s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":12239,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25274,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:19:02.818977  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:02.865724  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.047s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20328,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.866295  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:02.878688  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4500,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.879161  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:02.997934  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.119s	user 0.095s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1489,"lbm_read_time_us":7520,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23713,"lbm_writes_lt_1ms":443,"mutex_wait_us":358,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:02.998796  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:03.042336  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.043s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.042924  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:03.057849  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.058420  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushMRSOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:03.089183  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushMRSOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.031s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1493,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1788,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:03.090214  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling LogGCOp(ff3154611c8146e78a4fc05411ce2059): free 121006453 bytes of WAL
I20260812 06:19:03.090469  2511 log_reader.cc:385] T ff3154611c8146e78a4fc05411ce2059: removed 12 log segments from log reader
I20260812 06:19:03.090540  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000015 (ops 72-76)
I20260812 06:19:03.090579  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000016 (ops 77-81)
I20260812 06:19:03.090664  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000017 (ops 82-86)
I20260812 06:19:03.090708  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000018 (ops 87-91)
I20260812 06:19:03.090731  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000019 (ops 92-96)
I20260812 06:19:03.090754  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000020 (ops 97-101)
I20260812 06:19:03.090801  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000021 (ops 102-106)
I20260812 06:19:03.090862  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000022 (ops 107-111)
I20260812 06:19:03.090899  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000023 (ops 112-116)
I20260812 06:19:03.090952  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000024 (ops 117-120)
I20260812 06:19:03.090989  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000025 (ops 121-125)
I20260812 06:19:03.091053  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000026 (ops 126-130)
I20260812 06:19:03.117832  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: LogGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:03.118253  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=6.157687
I20260812 06:19:03.147183  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.029s	user 0.009s	sys 0.017s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12390,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:03.147775  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling LogGCOp(ff3154611c8146e78a4fc05411ce2059): free 11564893 bytes of WAL
I20260812 06:19:03.148093  2511 log_reader.cc:385] T ff3154611c8146e78a4fc05411ce2059: removed 1 log segments from log reader
I20260812 06:19:03.148175  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000027 (ops 131-134)
I20260812 06:19:03.151582  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: LogGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:03.152068  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:03.328857  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.177s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836259,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":533,"lbm_read_time_us":13125,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35774,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:03.329669  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=14.095187
I20260812 06:19:03.380998  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.051s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22937,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.381572  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059): 483 bytes on disk
I20260812 06:19:03.382010  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059) 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:03.382483  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:03.402247  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.402730  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:03.561466  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.159s	user 0.116s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":553,"lbm_read_time_us":10951,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29234,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:19:03.562034  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=14.095187
I20260812 06:19:03.605091  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.043s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19795,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.605549  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:03.742645  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.137s	user 0.104s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":432,"lbm_read_time_us":11673,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23177,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:19:03.743393  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=10.126437
I20260812 06:19:03.780923  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.037s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.781564  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:03.801533  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.020s	user 0.009s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.802038  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:03.951139  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.149s	user 0.112s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":9560,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30287,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:03.951900  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=11.118625
I20260812 06:19:03.984414  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.032s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14219,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:03.985075  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:04.002645  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6024,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:04.003156  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:04.146391  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.143s	user 0.103s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":8418,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28102,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:19:04.147068  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=14.095187
I20260812 06:19:04.198860  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.052s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:04.199424  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=2.188937
I20260812 06:19:04.214908  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.215562  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:04.370041  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.154s	user 0.135s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":465,"lbm_read_time_us":9795,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31837,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:19:04.370918  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=12.110812
I20260812 06:19:04.412209  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.041s	user 0.029s	sys 0.008s Metrics: {"bytes_written":13702314,"delete_count":0,"lbm_write_time_us":17754,"lbm_writes_lt_1ms":337,"reinsert_count":0,"update_count":1670}
I20260812 06:19:04.412757  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.196750
I20260812 06:19:04.423352  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":3778,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:19:04.423856  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushMRSOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:04.460865  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushMRSOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.037s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1389,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1491,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":1920}
I20260812 06:19:04.461591  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling LogGCOp(ff3154611c8146e78a4fc05411ce2059): free 108988743 bytes of WAL
I20260812 06:19:04.461817  2511 log_reader.cc:385] T ff3154611c8146e78a4fc05411ce2059: removed 11 log segments from log reader
I20260812 06:19:04.461865  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000028 (ops 135-139)
I20260812 06:19:04.461895  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000029 (ops 140-144)
I20260812 06:19:04.461956  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000030 (ops 145-149)
I20260812 06:19:04.461988  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000031 (ops 150-154)
I20260812 06:19:04.462033  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000032 (ops 155-159)
I20260812 06:19:04.462086  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000033 (ops 160-164)
I20260812 06:19:04.462126  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000034 (ops 165-169)
I20260812 06:19:04.462165  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000035 (ops 170-174)
I20260812 06:19:04.462203  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000036 (ops 175-178)
I20260812 06:19:04.462241  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000037 (ops 179-183)
I20260812 06:19:04.462280  2511 log.cc:1079] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/ff3154611c8146e78a4fc05411ce2059/wal-000000038 (ops 184-188)
I20260812 06:19:04.487617  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: LogGCOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:04.487986  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059): 462 bytes on disk
I20260812 06:19:04.488402  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: UndoDeltaBlockGCOp(ff3154611c8146e78a4fc05411ce2059) 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:04.489012  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=6.157687
I20260812 06:19:04.514415  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.025s	user 0.021s	sys 0.000s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":9170,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:04.515233  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059): perf score=1.000000
I20260812 06:19:04.734516  2346 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.949s	user 1.832s	sys 0.122s
I20260812 06:19:04.739061  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: MajorDeltaCompactionOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.224s	user 0.152s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836239,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":979,"lbm_read_time_us":15150,"lbm_reads_lt_1ms":665,"lbm_write_time_us":39082,"lbm_writes_lt_1ms":643,"mutex_wait_us":284,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:19:04.739663  2602 maintenance_manager.cc:419] P c7fc93b0e2c14aa7a5bc72a4500f4710: Scheduling FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059): perf score=18.063937
I20260812 06:19:04.773556  2346 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.038s	user 0.006s	sys 0.000s
I20260812 06:19:04.774426  2346 tablet_server.cc:179] TabletServer@127.2.74.129:0 shutting down...
I20260812 06:19:04.799394  2511 maintenance_manager.cc:643] P c7fc93b0e2c14aa7a5bc72a4500f4710: FlushDeltaMemStoresOp(ff3154611c8146e78a4fc05411ce2059) complete. Timing: real 0.059s	user 0.041s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27143,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:04.800028  2346 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:04.800563  2346 tablet_replica.cc:333] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710: stopping tablet replica
I20260812 06:19:04.800786  2346 raft_consensus.cc:2243] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.800992  2346 raft_consensus.cc:2272] T ff3154611c8146e78a4fc05411ce2059 P c7fc93b0e2c14aa7a5bc72a4500f4710 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.816201  2346 tablet_server.cc:196] TabletServer@127.2.74.129:0 shutdown complete.
I20260812 06:19:04.820892  2346 master.cc:562] Master@127.2.74.190:36549 shutting down...
I20260812 06:19:04.824991  2346 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.825148  2346 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.825202  2346 tablet_replica.cc:333] T 00000000000000000000000000000000 P 64b2804780d94e33ba465e581caea9f0: stopping tablet replica
I20260812 06:19:04.837471  2346 master.cc:584] Master@127.2.74.190:36549 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5429 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:04.930614  2346 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.74.190:39209
I20260812 06:19:04.931033  2346 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:04.933285  2655 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:04.933262  2658 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:04.933542  2346 server_base.cc:1061] running on GCE node
W20260812 06:19:04.933382  2660 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:04.933880  2346 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:04.933964  2346 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:04.934003  2346 hybrid_clock.cc:648] HybridClock initialized: now 1786515544934003 us; error 0 us; skew 500 ppm
I20260812 06:19:04.934958  2346 webserver.cc:533] Webserver started at http://127.2.74.190:41723/ using document root <none> and password file <none>
I20260812 06:19:04.935145  2346 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:04.935218  2346 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:04.935307  2346 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:04.935807  2346 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/master-0-root/instance:
uuid: "b8dc027f1c384d5ab660835eca6d4530"
format_stamp: "Formatted at 2026-08-12 06:19:04 on dist-test-slave-44d2"
I20260812 06:19:04.937534  2346 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:04.938457  2669 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:04.938747  2346 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:04.938850  2346 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/master-0-root
uuid: "b8dc027f1c384d5ab660835eca6d4530"
format_stamp: "Formatted at 2026-08-12 06:19:04 on dist-test-slave-44d2"
I20260812 06:19:04.938968  2346 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-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:04.954239  2346 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:04.954723  2346 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:04.959643  2346 rpc_server.cc:307] RPC server started. Bound to: 127.2.74.190:39209
I20260812 06:19:04.978394  2758 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.74.190:39209 every 8 connection(s)
I20260812 06:19:04.978912  2759 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:04.980865  2759 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530: Bootstrap starting.
I20260812 06:19:04.981654  2759 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:04.982758  2759 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530: No bootstrap required, opened a new log
I20260812 06:19:04.983141  2759 raft_consensus.cc:359] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER }
I20260812 06:19:04.983229  2759 raft_consensus.cc:385] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:04.983253  2759 raft_consensus.cc:740] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b8dc027f1c384d5ab660835eca6d4530, State: Initialized, Role: FOLLOWER
I20260812 06:19:04.983417  2759 consensus_queue.cc:260] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [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: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER }
I20260812 06:19:04.983508  2759 raft_consensus.cc:399] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:04.983534  2759 raft_consensus.cc:493] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:04.983567  2759 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:04.984217  2759 raft_consensus.cc:515] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER }
I20260812 06:19:04.984329  2759 leader_election.cc:304] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [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: b8dc027f1c384d5ab660835eca6d4530; no voters: 
I20260812 06:19:04.984580  2759 leader_election.cc:290] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:04.984719  2763 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:04.984979  2763 raft_consensus.cc:697] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 1 LEADER]: Becoming Leader. State: Replica: b8dc027f1c384d5ab660835eca6d4530, State: Running, Role: LEADER
I20260812 06:19:04.985128  2759 sys_catalog.cc:565] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:04.985126  2763 consensus_queue.cc:237] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [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: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER }
I20260812 06:19:04.985602  2764 sys_catalog.cc:455] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b8dc027f1c384d5ab660835eca6d4530" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER } }
I20260812 06:19:04.985713  2764 sys_catalog.cc:458] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:04.985617  2767 sys_catalog.cc:455] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b8dc027f1c384d5ab660835eca6d4530. Latest consensus state: current_term: 1 leader_uuid: "b8dc027f1c384d5ab660835eca6d4530" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b8dc027f1c384d5ab660835eca6d4530" member_type: VOTER } }
I20260812 06:19:04.986030  2767 sys_catalog.cc:458] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:04.986330  2772 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:04.987011  2772 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:04.987223  2346 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:04.988993  2772 catalog_manager.cc:1383] Generated new cluster ID: e5de77904df84049922a7b7d13584479
I20260812 06:19:04.989061  2772 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.013064  2772 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.013670  2772 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.028283  2772 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530: Generated new TSK 0
I20260812 06:19:05.028580  2772 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.052408  2346 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.054877  2790 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:05.055099  2795 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:05.055404  2791 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:05.055526  2346 server_base.cc:1061] running on GCE node
I20260812 06:19:05.055752  2346 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.055797  2346 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:05.055815  2346 hybrid_clock.cc:648] HybridClock initialized: now 1786515545055815 us; error 0 us; skew 500 ppm
I20260812 06:19:05.056761  2346 webserver.cc:533] Webserver started at http://127.2.74.129:44181/ using document root <none> and password file <none>
I20260812 06:19:05.056918  2346 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.056963  2346 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.057026  2346 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.057451  2346 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/instance:
uuid: "ac5505294f764129b040a330ce810bfe"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-44d2"
I20260812 06:19:05.059036  2346 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:05.059970  2807 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:05.060364  2346 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:05.060461  2346 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root
uuid: "ac5505294f764129b040a330ce810bfe"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-44d2"
I20260812 06:19:05.060587  2346 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-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:05.068899  2346 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.069269  2346 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.069588  2346 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:05.070086  2346 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:05.070149  2346 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.070215  2346 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:05.070267  2346 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.074962  2346 rpc_server.cc:307] RPC server started. Bound to: 127.2.74.129:36263
I20260812 06:19:05.074992  2910 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.74.129:36263 every 8 connection(s)
I20260812 06:19:05.084642  2911 heartbeater.cc:344] Connected to a master server at 127.2.74.190:39209
I20260812 06:19:05.084751  2911 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:05.084940  2911 heartbeater.cc:507] Master 127.2.74.190:39209 requested a full tablet report, sending...
I20260812 06:19:05.085634  2702 ts_manager.cc:194] Registered new tserver with Master: ac5505294f764129b040a330ce810bfe (127.2.74.129:36263)
I20260812 06:19:05.086472  2702 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37582
I20260812 06:19:05.086623  2346 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011206122s
I20260812 06:19:05.093441  2702 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37584:
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:05.102216  2852 tablet_service.cc:1511] Processing CreateTablet for tablet 29f7985b4b4847188e4741f25dbeef97 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7ee0f462bbd2474cb9aafd15f1407eff]), partition=
I20260812 06:19:05.102458  2852 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 29f7985b4b4847188e4741f25dbeef97. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.104421  2931 tablet_bootstrap.cc:492] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Bootstrap starting.
I20260812 06:19:05.105322  2931 tablet_bootstrap.cc:654] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.106326  2931 tablet_bootstrap.cc:492] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: No bootstrap required, opened a new log
I20260812 06:19:05.106400  2931 ts_tablet_manager.cc:1403] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:05.106739  2931 raft_consensus.cc:359] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac5505294f764129b040a330ce810bfe" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 36263 } }
I20260812 06:19:05.106820  2931 raft_consensus.cc:385] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.106842  2931 raft_consensus.cc:740] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ac5505294f764129b040a330ce810bfe, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.106971  2931 consensus_queue.cc:260] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [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: "ac5505294f764129b040a330ce810bfe" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 36263 } }
I20260812 06:19:05.107057  2931 raft_consensus.cc:399] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.107082  2931 raft_consensus.cc:493] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.107121  2931 raft_consensus.cc:3060] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.107892  2931 raft_consensus.cc:515] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac5505294f764129b040a330ce810bfe" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 36263 } }
I20260812 06:19:05.108048  2931 leader_election.cc:304] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [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: ac5505294f764129b040a330ce810bfe; no voters: 
I20260812 06:19:05.108249  2931 leader_election.cc:290] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.108389  2934 raft_consensus.cc:2804] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.108641  2931 ts_tablet_manager.cc:1434] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:05.108665  2934 raft_consensus.cc:697] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 1 LEADER]: Becoming Leader. State: Replica: ac5505294f764129b040a330ce810bfe, State: Running, Role: LEADER
I20260812 06:19:05.108705  2911 heartbeater.cc:499] Master 127.2.74.190:39209 was elected leader, sending a full tablet report...
I20260812 06:19:05.108867  2934 consensus_queue.cc:237] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [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: "ac5505294f764129b040a330ce810bfe" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 36263 } }
I20260812 06:19:05.110077  2702 catalog_manager.cc:5719] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe reported cstate change: term changed from 0 to 1, leader changed from <none> to ac5505294f764129b040a330ce810bfe (127.2.74.129). New cstate: current_term: 1 leader_uuid: "ac5505294f764129b040a330ce810bfe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac5505294f764129b040a330ce810bfe" member_type: VOTER last_known_addr { host: "127.2.74.129" port: 36263 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:05.171231  2346 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.024s	sys 0.000s
I20260812 06:19:05.325960  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushMRSOp(29f7985b4b4847188e4741f25dbeef97): perf score=19.054940
I20260812 06:19:05.476017  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushMRSOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.150s	user 0.114s	sys 0.032s Metrics: {"bytes_written":12717737,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1117,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38550,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1792,"update_count":1550}
I20260812 06:19:05.476969  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling LogGCOp(29f7985b4b4847188e4741f25dbeef97): free 20743880 bytes of WAL
I20260812 06:19:05.477247  2818 log_reader.cc:385] T 29f7985b4b4847188e4741f25dbeef97: removed 2 log segments from log reader
I20260812 06:19:05.477367  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000001 (ops 1-6)
I20260812 06:19:05.477465  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000002 (ops 7-11)
I20260812 06:19:05.482654  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: LogGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:05.483050  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:05.507395  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4820,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.507921  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:05.522687  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.523195  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:05.697031  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.174s	user 0.115s	sys 0.052s 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":925,"lbm_read_time_us":12138,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32796,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":384,"threads_started":5,"update_count":2500}
I20260812 06:19:05.697630  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97): 16411393 bytes on disk
I20260812 06:19:05.698031  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4}
I20260812 06:19:05.698488  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:05.754187  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.056s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.754628  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:05.766183  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.766754  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:05.947070  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.180s	user 0.129s	sys 0.040s 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":375,"lbm_read_time_us":11292,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34320,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30464,"update_count":2500}
I20260812 06:19:05.947707  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:05.990998  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.043s	user 0.026s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18796,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.991695  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:06.146327  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.154s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":937,"lbm_read_time_us":11470,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26733,"lbm_writes_lt_1ms":443,"mutex_wait_us":151,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:19:06.147136  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:06.180114  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.033s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13467,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.180732  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:06.200798  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.020s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.201326  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:06.350886  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.149s	user 0.106s	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":486,"lbm_read_time_us":8136,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29523,"lbm_writes_lt_1ms":443,"mutex_wait_us":376,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:06.351747  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=11.118625
I20260812 06:19:06.399039  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.047s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18477,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:06.399500  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:06.420832  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.421271  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:06.430903  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3656,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.431430  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:06.581889  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.150s	user 0.118s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":453,"lbm_read_time_us":10052,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29850,"lbm_writes_lt_1ms":543,"mutex_wait_us":228,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:19:06.582533  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:06.619422  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.035s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14463,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:06.620060  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:06.633394  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4711,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.633841  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:06.755712  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.122s	user 0.084s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":310,"lbm_read_time_us":10103,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21615,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:06.756291  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:06.810508  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.054s	user 0.023s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18167,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.811256  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:06.823249  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.823735  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushMRSOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:06.855702  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushMRSOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1653,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1577,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:06.856377  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97): 482 bytes on disk
I20260812 06:19:06.856909  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.857398  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:07.013307  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.156s	user 0.100s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":375,"lbm_read_time_us":10041,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27112,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:07.014010  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling LogGCOp(29f7985b4b4847188e4741f25dbeef97): free 128867388 bytes of WAL
I20260812 06:19:07.014247  2818 log_reader.cc:385] T 29f7985b4b4847188e4741f25dbeef97: removed 13 log segments from log reader
I20260812 06:19:07.014299  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000003 (ops 12-16)
I20260812 06:19:07.014340  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000004 (ops 17-20)
I20260812 06:19:07.014375  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000005 (ops 21-25)
I20260812 06:19:07.014448  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000006 (ops 26-30)
I20260812 06:19:07.014484  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000007 (ops 31-35)
I20260812 06:19:07.014549  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000008 (ops 36-40)
I20260812 06:19:07.014585  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000009 (ops 41-44)
I20260812 06:19:07.014629  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000010 (ops 45-49)
I20260812 06:19:07.014662  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000011 (ops 50-54)
I20260812 06:19:07.014724  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000012 (ops 55-59)
I20260812 06:19:07.014760  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000013 (ops 60-64)
I20260812 06:19:07.014813  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000014 (ops 65-68)
I20260812 06:19:07.014851  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000015 (ops 69-73)
I20260812 06:19:07.048197  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: LogGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.034s	user 0.002s	sys 0.028s Metrics: {}
I20260812 06:19:07.048687  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:07.099984  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.051s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22946,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.100548  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:07.136664  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.036s	user 0.012s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.137216  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:07.153743  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.154382  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:07.366833  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.212s	user 0.126s	sys 0.085s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":629,"lbm_read_time_us":16471,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35662,"lbm_writes_lt_1ms":643,"mutex_wait_us":288,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":3000}
I20260812 06:19:07.367554  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:07.446597  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.079s	user 0.026s	sys 0.043s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.447206  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:07.459461  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.459925  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:07.655597  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.195s	user 0.137s	sys 0.047s 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":292,"lbm_read_time_us":14118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31756,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:07.656140  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:07.710240  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.054s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.710668  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:07.730775  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.731398  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:07.926949  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.195s	user 0.139s	sys 0.052s 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":720,"lbm_read_time_us":13238,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32368,"lbm_writes_lt_1ms":543,"mutex_wait_us":116,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:19:07.927812  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:07.980971  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.053s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22454,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.981505  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:07.995427  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.995980  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:08.186233  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.190s	user 0.121s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":10799,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28519,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:08.186968  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:08.239367  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.052s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19607,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.239882  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:08.251624  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.252301  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:08.413535  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.161s	user 0.126s	sys 0.032s 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":201,"lbm_read_time_us":11797,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34867,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:08.414366  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=11.118625
I20260812 06:19:08.453696  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.039s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16911,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:08.454493  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:08.471220  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5209,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.471657  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushMRSOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:08.514775  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushMRSOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.043s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1624,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:08.515481  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=3.181125
I20260812 06:19:08.527905  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":4824,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:19:08.528429  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling LogGCOp(29f7985b4b4847188e4741f25dbeef97): free 121006505 bytes of WAL
I20260812 06:19:08.528681  2818 log_reader.cc:385] T 29f7985b4b4847188e4741f25dbeef97: removed 12 log segments from log reader
I20260812 06:19:08.528745  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000016 (ops 74-78)
I20260812 06:19:08.528800  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000017 (ops 79-83)
I20260812 06:19:08.528851  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000018 (ops 84-88)
I20260812 06:19:08.528892  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000019 (ops 89-93)
I20260812 06:19:08.528924  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000020 (ops 94-98)
I20260812 06:19:08.528967  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000021 (ops 99-103)
I20260812 06:19:08.529023  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000022 (ops 104-108)
I20260812 06:19:08.529060  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000023 (ops 109-113)
I20260812 06:19:08.529098  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000024 (ops 114-118)
I20260812 06:19:08.529134  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000025 (ops 119-122)
I20260812 06:19:08.529170  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000026 (ops 123-127)
I20260812 06:19:08.529206  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000027 (ops 128-132)
I20260812 06:19:08.557282  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: LogGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:08.557737  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97): 483 bytes on disk
I20260812 06:19:08.558251  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: UndoDeltaBlockGCOp(29f7985b4b4847188e4741f25dbeef97) 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:08.558799  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=3.181125
I20260812 06:19:08.570628  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4266759,"delete_count":0,"lbm_write_time_us":4566,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:19:08.571143  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling LogGCOp(29f7985b4b4847188e4741f25dbeef97): free 11564893 bytes of WAL
I20260812 06:19:08.571372  2818 log_reader.cc:385] T 29f7985b4b4847188e4741f25dbeef97: removed 1 log segments from log reader
I20260812 06:19:08.571441  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000028 (ops 133-136)
I20260812 06:19:08.574345  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: LogGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:08.574659  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:08.596462  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.022s	user 0.004s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.597245  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:08.826550  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.229s	user 0.173s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979852,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1391,"lbm_read_time_us":17289,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41708,"lbm_writes_lt_1ms":743,"mutex_wait_us":618,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:08.827234  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:08.882529  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.055s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.883113  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:08.899991  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.900426  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.072171  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.172s	user 0.114s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":11740,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27015,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:09.072707  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:09.126266  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.053s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:09.126762  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:09.137288  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4241,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.137686  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.311539  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.174s	user 0.114s	sys 0.060s 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":140,"lbm_read_time_us":13783,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29464,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:09.312245  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:09.342777  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.030s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13305,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.343271  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:09.356904  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.357344  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.492766  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.135s	user 0.099s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":8462,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25007,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:09.493479  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:09.531348  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.038s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14396,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.531937  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:09.547549  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.548300  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.672921  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.124s	user 0.103s	sys 0.021s 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":1089,"lbm_read_time_us":10779,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22584,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:09.673655  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:09.712729  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.038s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17620,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.713189  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:09.725155  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.725641  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.855355  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.130s	user 0.097s	sys 0.032s 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":182,"lbm_read_time_us":9063,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25788,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:09.856904  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=10.126437
I20260812 06:19:09.918673  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.062s	user 0.032s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21926,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.919456  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=2.188937
I20260812 06:19:09.941320  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.941885  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushMRSOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:09.979207  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushMRSOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.037s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1320,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1854,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:09.979893  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling LogGCOp(29f7985b4b4847188e4741f25dbeef97): free 112239559 bytes of WAL
I20260812 06:19:09.980136  2818 log_reader.cc:385] T 29f7985b4b4847188e4741f25dbeef97: removed 11 log segments from log reader
I20260812 06:19:09.980207  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000029 (ops 137-141)
I20260812 06:19:09.980280  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000030 (ops 142-146)
I20260812 06:19:09.980340  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000031 (ops 147-151)
I20260812 06:19:09.980422  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000032 (ops 152-156)
I20260812 06:19:09.980479  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000033 (ops 157-161)
I20260812 06:19:09.980576  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000034 (ops 162-166)
I20260812 06:19:09.980616  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000035 (ops 167-171)
I20260812 06:19:09.980688  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000036 (ops 172-176)
I20260812 06:19:09.980727  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000037 (ops 177-181)
I20260812 06:19:09.980796  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000038 (ops 182-186)
I20260812 06:19:09.980835  2818 log.cc:1079] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: Deleting log segment in path: /tmp/dist-test-taskd4b4od/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539491089-2346-0/minicluster-data/ts-0-root/wals/29f7985b4b4847188e4741f25dbeef97/wal-000000039 (ops 187-190)
I20260812 06:19:10.003981  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: LogGCOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.024s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:10.004410  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=6.157687
I20260812 06:19:10.031366  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.027s	user 0.021s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10547,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:10.031888  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:10.188369  2346 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.017s	user 1.876s	sys 0.190s
I20260812 06:19:10.221082  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.189s	user 0.127s	sys 0.062s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":13824,"lbm_reads_lt_1ms":661,"lbm_write_time_us":34314,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:19:10.221578  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97): perf score=14.095187
I20260812 06:19:10.255383  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: FlushDeltaMemStoresOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16255,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.255882  2914 maintenance_manager.cc:419] P ac5505294f764129b040a330ce810bfe: Scheduling MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97): perf score=1.000000
I20260812 06:19:10.274876  2346 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.000s	sys 0.000s
I20260812 06:19:10.275391  2346 tablet_server.cc:179] TabletServer@127.2.74.129:0 shutting down...
I20260812 06:19:10.382968  2818 maintenance_manager.cc:643] P ac5505294f764129b040a330ce810bfe: MajorDeltaCompactionOp(29f7985b4b4847188e4741f25dbeef97) complete. Timing: real 0.127s	user 0.079s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":363,"lbm_read_time_us":11493,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23496,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:10.383697  2346 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:10.383960  2346 tablet_replica.cc:333] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe: stopping tablet replica
I20260812 06:19:10.384133  2346 raft_consensus.cc:2243] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.384305  2346 raft_consensus.cc:2272] T 29f7985b4b4847188e4741f25dbeef97 P ac5505294f764129b040a330ce810bfe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.399091  2346 tablet_server.cc:196] TabletServer@127.2.74.129:0 shutdown complete.
I20260812 06:19:10.421345  2346 master.cc:562] Master@127.2.74.190:39209 shutting down...
I20260812 06:19:10.424856  2346 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.425045  2346 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.425133  2346 tablet_replica.cc:333] T 00000000000000000000000000000000 P b8dc027f1c384d5ab660835eca6d4530: stopping tablet replica
I20260812 06:19:10.437518  2346 master.cc:584] Master@127.2.74.190:39209 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5604 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11035 ms total)

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