[==========] 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:03.678922 12166 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.225.190:44231
I20260812 06:18:03.680060 12166 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:03.680727 12166 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:03.687285 12182 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:03.687273 12179 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:03.687520 12166 server_base.cc:1061] running on GCE node
W20260812 06:18:03.687649 12184 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:03.688210 12166 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:03.688308 12166 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:03.688359 12166 hybrid_clock.cc:648] HybridClock initialized: now 1786515483688356 us; error 0 us; skew 500 ppm
I20260812 06:18:03.690348 12166 webserver.cc:533] Webserver started at http://127.11.225.190:33463/ using document root <none> and password file <none>
I20260812 06:18:03.690991 12166 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:03.691056 12166 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:03.691309 12166 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:03.693169 12166 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/master-0-root/instance:
uuid: "159729663b074f02acbb0d76df4c5251"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-twwt"
I20260812 06:18:03.696959 12166 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:03.699375 12194 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:03.700569 12166 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:03.700730 12166 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/master-0-root
uuid: "159729663b074f02acbb0d76df4c5251"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-twwt"
I20260812 06:18:03.700851 12166 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-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:03.729745 12166 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:03.730546 12166 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:03.730786 12166 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:03.739420 12166 rpc_server.cc:307] RPC server started. Bound to: 127.11.225.190:44231
I20260812 06:18:03.739440 12290 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.225.190:44231 every 8 connection(s)
I20260812 06:18:03.741990 12291 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:03.747972 12291 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: Bootstrap starting.
I20260812 06:18:03.750566 12291 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:03.751580 12291 log.cc:826] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:03.753559 12291 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: No bootstrap required, opened a new log
I20260812 06:18:03.756578 12291 raft_consensus.cc:359] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "159729663b074f02acbb0d76df4c5251" member_type: VOTER }
I20260812 06:18:03.756758 12291 raft_consensus.cc:385] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:03.756880 12291 raft_consensus.cc:740] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 159729663b074f02acbb0d76df4c5251, State: Initialized, Role: FOLLOWER
I20260812 06:18:03.757519 12291 consensus_queue.cc:260] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [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: "159729663b074f02acbb0d76df4c5251" member_type: VOTER }
I20260812 06:18:03.757663 12291 raft_consensus.cc:399] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:03.757712 12291 raft_consensus.cc:493] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:03.757805 12291 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:03.758684 12291 raft_consensus.cc:515] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "159729663b074f02acbb0d76df4c5251" member_type: VOTER }
I20260812 06:18:03.759119 12291 leader_election.cc:304] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [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: 159729663b074f02acbb0d76df4c5251; no voters: 
I20260812 06:18:03.759438 12291 leader_election.cc:290] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:03.759603 12296 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:03.759912 12296 raft_consensus.cc:697] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 1 LEADER]: Becoming Leader. State: Replica: 159729663b074f02acbb0d76df4c5251, State: Running, Role: LEADER
I20260812 06:18:03.760357 12296 consensus_queue.cc:237] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [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: "159729663b074f02acbb0d76df4c5251" member_type: VOTER }
I20260812 06:18:03.760655 12291 sys_catalog.cc:565] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:03.762589 12298 sys_catalog.cc:455] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "159729663b074f02acbb0d76df4c5251" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "159729663b074f02acbb0d76df4c5251" member_type: VOTER } }
I20260812 06:18:03.762645 12303 sys_catalog.cc:455] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 159729663b074f02acbb0d76df4c5251. Latest consensus state: current_term: 1 leader_uuid: "159729663b074f02acbb0d76df4c5251" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "159729663b074f02acbb0d76df4c5251" member_type: VOTER } }
I20260812 06:18:03.762796 12303 sys_catalog.cc:458] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:03.762799 12298 sys_catalog.cc:458] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:03.763391 12166 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:03.765425 12328 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:03.765518 12328 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:03.765589 12326 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:03.766378 12326 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:03.771750 12326 catalog_manager.cc:1383] Generated new cluster ID: ea30c47191574548b104e5814784dbfb
I20260812 06:18:03.771831 12326 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:03.785884 12326 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:03.787222 12326 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:03.796727 12326 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: Generated new TSK 0
I20260812 06:18:03.797477 12326 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:03.828387 12166 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:03.831249 12332 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:03.831329 12333 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:03.831529 12166 server_base.cc:1061] running on GCE node
W20260812 06:18:03.831518 12337 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:03.831790 12166 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:03.831854 12166 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:03.831879 12166 hybrid_clock.cc:648] HybridClock initialized: now 1786515483831879 us; error 0 us; skew 500 ppm
I20260812 06:18:03.832911 12166 webserver.cc:533] Webserver started at http://127.11.225.129:34391/ using document root <none> and password file <none>
I20260812 06:18:03.833094 12166 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:03.833158 12166 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:03.833237 12166 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:03.833719 12166 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/instance:
uuid: "2070b55616a34045b6c1ea5ef3752c0e"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-twwt"
I20260812 06:18:03.835706 12166 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:03.836856 12348 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:03.837157 12166 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:03.837222 12166 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root
uuid: "2070b55616a34045b6c1ea5ef3752c0e"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-twwt"
I20260812 06:18:03.837320 12166 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-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:03.847421 12166 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:03.847947 12166 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:03.848477 12166 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:03.849349 12166 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:03.849400 12166 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.849473 12166 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:03.849514 12166 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.856936 12166 rpc_server.cc:307] RPC server started. Bound to: 127.11.225.129:42147
I20260812 06:18:03.856992 12461 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.225.129:42147 every 8 connection(s)
I20260812 06:18:03.868398 12464 heartbeater.cc:344] Connected to a master server at 127.11.225.190:44231
I20260812 06:18:03.868775 12464 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:03.869405 12464 heartbeater.cc:507] Master 127.11.225.190:44231 requested a full tablet report, sending...
I20260812 06:18:03.871207 12223 ts_manager.cc:194] Registered new tserver with Master: 2070b55616a34045b6c1ea5ef3752c0e (127.11.225.129:42147)
I20260812 06:18:03.871475 12166 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013790736s
I20260812 06:18:03.872889 12223 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48308
I20260812 06:18:03.882654 12223 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48316:
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:03.899976 12404 tablet_service.cc:1511] Processing CreateTablet for tablet 4344e42f2581471fafb653bbda32e14c (DEFAULT_TABLE table=heavy-update-compaction-test [id=d1bb32258c4f40b4a5d76e223fb4d735]), partition=
I20260812 06:18:03.900538 12404 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4344e42f2581471fafb653bbda32e14c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:03.903391 12495 tablet_bootstrap.cc:492] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Bootstrap starting.
I20260812 06:18:03.904551 12495 tablet_bootstrap.cc:654] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:03.906092 12495 tablet_bootstrap.cc:492] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: No bootstrap required, opened a new log
I20260812 06:18:03.906265 12495 ts_tablet_manager.cc:1403] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:03.906833 12495 raft_consensus.cc:359] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2070b55616a34045b6c1ea5ef3752c0e" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 42147 } }
I20260812 06:18:03.906967 12495 raft_consensus.cc:385] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:03.907016 12495 raft_consensus.cc:740] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2070b55616a34045b6c1ea5ef3752c0e, State: Initialized, Role: FOLLOWER
I20260812 06:18:03.907192 12495 consensus_queue.cc:260] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [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: "2070b55616a34045b6c1ea5ef3752c0e" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 42147 } }
I20260812 06:18:03.907302 12495 raft_consensus.cc:399] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:03.907361 12495 raft_consensus.cc:493] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:03.907470 12495 raft_consensus.cc:3060] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:03.908550 12495 raft_consensus.cc:515] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2070b55616a34045b6c1ea5ef3752c0e" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 42147 } }
I20260812 06:18:03.908718 12495 leader_election.cc:304] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [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: 2070b55616a34045b6c1ea5ef3752c0e; no voters: 
I20260812 06:18:03.908975 12495 leader_election.cc:290] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:03.909081 12497 raft_consensus.cc:2804] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:03.909283 12497 raft_consensus.cc:697] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 1 LEADER]: Becoming Leader. State: Replica: 2070b55616a34045b6c1ea5ef3752c0e, State: Running, Role: LEADER
I20260812 06:18:03.909409 12495 ts_tablet_manager.cc:1434] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:03.909541 12497 consensus_queue.cc:237] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [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: "2070b55616a34045b6c1ea5ef3752c0e" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 42147 } }
I20260812 06:18:03.909734 12464 heartbeater.cc:499] Master 127.11.225.190:44231 was elected leader, sending a full tablet report...
I20260812 06:18:03.912881 12223 catalog_manager.cc:5719] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e reported cstate change: term changed from 0 to 1, leader changed from <none> to 2070b55616a34045b6c1ea5ef3752c0e (127.11.225.129). New cstate: current_term: 1 leader_uuid: "2070b55616a34045b6c1ea5ef3752c0e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2070b55616a34045b6c1ea5ef3752c0e" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 42147 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:03.985598 12166 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.021s	sys 0.008s
I20260812 06:18:04.108271 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushMRSOp(4344e42f2581471fafb653bbda32e14c): perf score=15.086190
I20260812 06:18:04.277947 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushMRSOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.169s	user 0.121s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":204,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1163,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41170,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":1920,"thread_start_us":127,"threads_started":1,"update_count":1500}
I20260812 06:18:04.279313 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 8725963 bytes of WAL
I20260812 06:18:04.279649 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 1 log segments from log reader
I20260812 06:18:04.279723 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000001 (ops 1-6)
I20260812 06:18:04.282326 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:04.282740 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:04.301357 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.301862 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c): 12308959 bytes on disk
I20260812 06:18:04.302469 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.302963 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:04.318584 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.319164 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:04.522302 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.203s	user 0.098s	sys 0.090s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1036,"lbm_read_time_us":12427,"lbm_reads_lt_1ms":569,"lbm_write_time_us":32452,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":315,"threads_started":5,"update_count":2500}
I20260812 06:18:04.522900 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:04.572683 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.050s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.573259 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:04.585470 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.586184 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:04.736366 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.150s	user 0.109s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":10849,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29414,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:18:04.736968 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=11.118625
I20260812 06:18:04.771229 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.034s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14595,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:04.771893 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:04.798991 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.027s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5343,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:04.799531 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:04.814934 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.815522 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:04.974781 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.159s	user 0.113s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":566,"lbm_read_time_us":11081,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33498,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:18:04.975509 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=10.126437
I20260812 06:18:05.012642 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.037s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15917,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.013284 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:05.028064 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.015s	user 0.004s	sys 0.008s 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:18:05.028648 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:05.162587 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.134s	user 0.117s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1018,"lbm_read_time_us":8778,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26978,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.163767 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=10.126437
I20260812 06:18:05.206073 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18925,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.206696 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:05.219426 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.219897 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:05.362005 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.142s	user 0.101s	sys 0.040s 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":1196,"lbm_read_time_us":9992,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27829,"lbm_writes_lt_1ms":443,"mutex_wait_us":543,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:05.364956 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=10.126437
I20260812 06:18:05.417337 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.051s	user 0.038s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17507,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.418258 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:05.434178 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.434764 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushMRSOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:05.463039 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushMRSOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.028s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1386,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1441,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:05.463874 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 115943163 bytes of WAL
I20260812 06:18:05.464172 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 11 log segments from log reader
I20260812 06:18:05.464221 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000002 (ops 7-11)
I20260812 06:18:05.464282 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000003 (ops 12-17)
I20260812 06:18:05.464326 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000004 (ops 18-22)
I20260812 06:18:05.464376 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000005 (ops 23-27)
I20260812 06:18:05.464455 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000006 (ops 28-32)
I20260812 06:18:05.464509 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000007 (ops 33-37)
I20260812 06:18:05.464545 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000008 (ops 38-42)
I20260812 06:18:05.464583 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000009 (ops 43-46)
I20260812 06:18:05.464624 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000010 (ops 47-51)
I20260812 06:18:05.464663 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000011 (ops 52-56)
I20260812 06:18:05.464704 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000012 (ops 57-61)
I20260812 06:18:05.494099 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:05.494712 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c): 447 bytes on disk
I20260812 06:18:05.495198 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.495676 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=3.181125
I20260812 06:18:05.510887 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:05.511343 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:05.521355 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3767,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:05.521858 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:05.721642 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.199s	user 0.123s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836365,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1210,"lbm_read_time_us":14600,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32658,"lbm_writes_lt_1ms":643,"mutex_wait_us":414,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:18:05.722409 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:05.769941 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.047s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21148,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.770740 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:05.933877 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.163s	user 0.096s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":175,"lbm_read_time_us":10510,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27193,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:05.934378 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:05.991071 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.057s	user 0.028s	sys 0.022s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.991587 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:06.004079 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.005252 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:06.200910 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.195s	user 0.136s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":867,"lbm_read_time_us":12848,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32456,"lbm_writes_lt_1ms":543,"mutex_wait_us":349,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:18:06.201550 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=11.118625
I20260812 06:18:06.239401 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.038s	user 0.034s	sys 0.003s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16215,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:06.240090 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:06.255887 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5466,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:06.256421 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:06.395581 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.139s	user 0.111s	sys 0.028s 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":307,"lbm_read_time_us":9648,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27765,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34816,"update_count":2000}
I20260812 06:18:06.396382 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=11.118625
I20260812 06:18:06.431705 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.035s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15642,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:06.432301 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:06.445204 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:06.445689 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:06.586128 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.140s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":9860,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28571,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:18:06.586997 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=10.126437
I20260812 06:18:06.629179 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18127,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:06.629885 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:06.641856 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.642925 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:06.781479 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.138s	user 0.105s	sys 0.033s 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":358,"lbm_read_time_us":10184,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27766,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":40064,"update_count":2000}
I20260812 06:18:06.782716 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=10.126437
I20260812 06:18:06.827836 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.045s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12553635,"delete_count":0,"lbm_write_time_us":15868,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1530}
I20260812 06:18:06.828420 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:06.839998 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4188,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:06.840838 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:07.007072 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.166s	user 0.098s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631307,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":14853,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27335,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:07.011422 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=11.118625
I20260812 06:18:07.045859 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12635684,"delete_count":0,"lbm_write_time_us":15098,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:18:07.046603 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:07.063017 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":6051,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:07.063683 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushMRSOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:07.095237 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushMRSOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1461,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1528,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:07.096567 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 129320510 bytes of WAL
I20260812 06:18:07.096869 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 13 log segments from log reader
I20260812 06:18:07.096952 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000013 (ops 62-66)
I20260812 06:18:07.097048 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000014 (ops 67-70)
I20260812 06:18:07.097088 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000015 (ops 71-75)
I20260812 06:18:07.097123 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000016 (ops 76-80)
I20260812 06:18:07.097167 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000017 (ops 81-85)
I20260812 06:18:07.097209 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000018 (ops 86-90)
I20260812 06:18:07.097280 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000019 (ops 91-94)
I20260812 06:18:07.097319 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000020 (ops 95-99)
I20260812 06:18:07.097371 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000021 (ops 100-104)
I20260812 06:18:07.097416 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000022 (ops 105-109)
I20260812 06:18:07.097458 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000023 (ops 110-114)
I20260812 06:18:07.097500 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000024 (ops 115-119)
I20260812 06:18:07.097543 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000025 (ops 120-124)
I20260812 06:18:07.130424 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.034s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:07.131052 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c): 482 bytes on disk
I20260812 06:18:07.131645 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:07.132273 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=6.157687
I20260812 06:18:07.162497 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.030s	user 0.019s	sys 0.007s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":9387,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:07.163102 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 11564883 bytes of WAL
I20260812 06:18:07.163403 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 1 log segments from log reader
I20260812 06:18:07.163455 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000026 (ops 125-128)
I20260812 06:18:07.166021 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:07.166404 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:07.374405 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.208s	user 0.125s	sys 0.081s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836251,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":278,"lbm_read_time_us":15734,"lbm_reads_lt_1ms":665,"lbm_write_time_us":37294,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:18:07.378782 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=15.087375
I20260812 06:18:07.454715 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.074s	user 0.024s	sys 0.038s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":25597,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"mutex_wait_us":2,"reinsert_count":0,"update_count":2050}
I20260812 06:18:07.455300 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=6.157687
I20260812 06:18:07.475977 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8169,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:07.477515 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:07.679329 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.202s	user 0.137s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":497,"lbm_read_time_us":15468,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35608,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":3000}
I20260812 06:18:07.679975 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:07.737102 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:07.737668 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:07.749534 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.750403 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:07.942576 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.191s	user 0.115s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":710,"lbm_read_time_us":12250,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32959,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:07.943178 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:08.013378 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.070s	user 0.022s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22962,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.014003 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.031476 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.032222 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:08.237341 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.205s	user 0.115s	sys 0.080s 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":448,"lbm_read_time_us":16101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34172,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:08.238287 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:08.312608 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.074s	user 0.036s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29769,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.313297 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.324748 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.325270 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:08.512953 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.187s	user 0.103s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":13021,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32800,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:18:08.513628 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=11.118625
I20260812 06:18:08.552937 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16993,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:08.553563 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.573964 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.020s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.574492 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.602317 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.028s	user 0.016s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5745,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.603080 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:08.802574 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.199s	user 0.152s	sys 0.038s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":924,"lbm_read_time_us":13731,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32981,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:18:08.803369 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:08.858829 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.055s	user 0.021s	sys 0.030s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23321,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.859331 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.871788 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.872331 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushMRSOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:08.916787 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushMRSOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.044s	user 0.032s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1321,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1952,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:08.917527 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 121006692 bytes of WAL
I20260812 06:18:08.917781 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 12 log segments from log reader
I20260812 06:18:08.917830 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000027 (ops 129-133)
I20260812 06:18:08.917860 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000028 (ops 134-138)
I20260812 06:18:08.917927 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000029 (ops 139-143)
I20260812 06:18:08.917986 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000030 (ops 144-148)
I20260812 06:18:08.918028 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000031 (ops 149-152)
I20260812 06:18:08.918092 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000032 (ops 153-157)
I20260812 06:18:08.918139 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000033 (ops 158-162)
I20260812 06:18:08.918182 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000034 (ops 163-167)
I20260812 06:18:08.918221 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000035 (ops 168-172)
I20260812 06:18:08.918259 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000036 (ops 173-177)
I20260812 06:18:08.918298 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000037 (ops 178-182)
I20260812 06:18:08.918336 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000038 (ops 183-187)
I20260812 06:18:08.947667 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:08.948252 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c): 493 bytes on disk
I20260812 06:18:08.948850 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: UndoDeltaBlockGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:18:08.949540 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=3.181125
I20260812 06:18:08.965829 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4545,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:08.966327 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling LogGCOp(4344e42f2581471fafb653bbda32e14c): free 12017952 bytes of WAL
I20260812 06:18:08.966557 12356 log_reader.cc:385] T 4344e42f2581471fafb653bbda32e14c: removed 1 log segments from log reader
I20260812 06:18:08.966656 12356 log.cc:1079] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/4344e42f2581471fafb653bbda32e14c/wal-000000039 (ops 188-192)
I20260812 06:18:08.969131 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: LogGCOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:08.969472 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=2.188937
I20260812 06:18:08.982897 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.983583 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:09.179302 12166 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.194s	user 1.884s	sys 0.164s
I20260812 06:18:09.213239 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.229s	user 0.132s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938779,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16085,"lbm_reads_lt_1ms":762,"lbm_write_time_us":39381,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:18:09.213876 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c): perf score=14.095187
I20260812 06:18:09.248507 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: FlushDeltaMemStoresOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.034s	user 0.030s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16829,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.249061 12467 maintenance_manager.cc:419] P 2070b55616a34045b6c1ea5ef3752c0e: Scheduling MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c): perf score=1.000000
I20260812 06:18:09.296859 12166 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.117s	user 0.000s	sys 0.002s
I20260812 06:18:09.297571 12166 tablet_server.cc:179] TabletServer@127.11.225.129:0 shutting down...
I20260812 06:18:09.384246 12356 maintenance_manager.cc:643] P 2070b55616a34045b6c1ea5ef3752c0e: MajorDeltaCompactionOp(4344e42f2581471fafb653bbda32e14c) complete. Timing: real 0.135s	user 0.100s	sys 0.034s 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":360,"lbm_read_time_us":10795,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27655,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:18:09.385049 12166 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:09.385475 12166 tablet_replica.cc:333] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e: stopping tablet replica
I20260812 06:18:09.385744 12166 raft_consensus.cc:2243] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:09.385998 12166 raft_consensus.cc:2272] T 4344e42f2581471fafb653bbda32e14c P 2070b55616a34045b6c1ea5ef3752c0e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:09.402307 12166 tablet_server.cc:196] TabletServer@127.11.225.129:0 shutdown complete.
I20260812 06:18:09.424783 12166 master.cc:562] Master@127.11.225.190:44231 shutting down...
I20260812 06:18:09.428721 12166 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:09.428917 12166 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:09.428977 12166 tablet_replica.cc:333] T 00000000000000000000000000000000 P 159729663b074f02acbb0d76df4c5251: stopping tablet replica
I20260812 06:18:09.441591 12166 master.cc:584] Master@127.11.225.190:44231 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5857 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:09.536130 12166 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.225.190:46597
I20260812 06:18:09.536603 12166 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.538872 12537 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:18:09.538853 12529 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:09.538983 12166 server_base.cc:1061] running on GCE node
W20260812 06:18:09.538853 12533 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:09.539353 12166 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.539398 12166 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:09.539413 12166 hybrid_clock.cc:648] HybridClock initialized: now 1786515489539413 us; error 0 us; skew 500 ppm
I20260812 06:18:09.540442 12166 webserver.cc:533] Webserver started at http://127.11.225.190:45773/ using document root <none> and password file <none>
I20260812 06:18:09.540642 12166 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.540694 12166 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.540956 12166 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.541522 12166 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/master-0-root/instance:
uuid: "fd9dd51b40ba4941bc51851e4c12ca28"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-twwt"
I20260812 06:18:09.543268 12166 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.003s
I20260812 06:18:09.544291 12542 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:09.544601 12166 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:09.544699 12166 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/master-0-root
uuid: "fd9dd51b40ba4941bc51851e4c12ca28"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-twwt"
I20260812 06:18:09.544823 12166 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-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:09.552563 12166 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.552973 12166 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.557646 12166 rpc_server.cc:307] RPC server started. Bound to: 127.11.225.190:46597
I20260812 06:18:09.560598 12630 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.225.190:46597 every 8 connection(s)
I20260812 06:18:09.561249 12631 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:09.576483 12631 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28: Bootstrap starting.
I20260812 06:18:09.577498 12631 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.578944 12631 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28: No bootstrap required, opened a new log
I20260812 06:18:09.579440 12631 raft_consensus.cc:359] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER }
I20260812 06:18:09.579567 12631 raft_consensus.cc:385] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.579635 12631 raft_consensus.cc:740] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fd9dd51b40ba4941bc51851e4c12ca28, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.579836 12631 consensus_queue.cc:260] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [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: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER }
I20260812 06:18:09.579938 12631 raft_consensus.cc:399] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.579984 12631 raft_consensus.cc:493] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.580039 12631 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.580881 12631 raft_consensus.cc:515] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER }
I20260812 06:18:09.581059 12631 leader_election.cc:304] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [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: fd9dd51b40ba4941bc51851e4c12ca28; no voters: 
I20260812 06:18:09.581296 12631 leader_election.cc:290] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.581503 12634 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.581781 12634 raft_consensus.cc:697] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 1 LEADER]: Becoming Leader. State: Replica: fd9dd51b40ba4941bc51851e4c12ca28, State: Running, Role: LEADER
I20260812 06:18:09.581897 12631 sys_catalog.cc:565] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:09.581967 12634 consensus_queue.cc:237] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [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: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER }
I20260812 06:18:09.582480 12637 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [sys.catalog]: SysCatalogTable state changed. Reason: New leader fd9dd51b40ba4941bc51851e4c12ca28. Latest consensus state: current_term: 1 leader_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER } }
I20260812 06:18:09.582580 12637 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:09.582459 12636 sys_catalog.cc:455] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd9dd51b40ba4941bc51851e4c12ca28" member_type: VOTER } }
I20260812 06:18:09.582690 12636 sys_catalog.cc:458] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:09.582916 12643 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:09.584129 12643 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:09.586885 12166 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:09.587129 12643 catalog_manager.cc:1383] Generated new cluster ID: 9b2925ca519444dd87cf706a025def58
I20260812 06:18:09.587196 12643 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:09.598285 12643 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:09.599020 12643 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:09.605518 12643 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28: Generated new TSK 0
I20260812 06:18:09.605762 12643 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:09.619488 12166 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.621626 12664 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:09.621744 12663 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:09.621855 12166 server_base.cc:1061] running on GCE node
W20260812 06:18:09.621685 12669 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:09.622128 12166 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.622174 12166 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:09.622190 12166 hybrid_clock.cc:648] HybridClock initialized: now 1786515489622190 us; error 0 us; skew 500 ppm
I20260812 06:18:09.623240 12166 webserver.cc:533] Webserver started at http://127.11.225.129:43099/ using document root <none> and password file <none>
I20260812 06:18:09.623436 12166 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.623492 12166 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.623579 12166 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.624042 12166 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/instance:
uuid: "0467f871e49a4ea7a351bb3ae91d8e61"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-twwt"
I20260812 06:18:09.625658 12166 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:09.626825 12675 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:09.627101 12166 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:09.627169 12166 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root
uuid: "0467f871e49a4ea7a351bb3ae91d8e61"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-twwt"
I20260812 06:18:09.627231 12166 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-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:09.639161 12166 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.639564 12166 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.639849 12166 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:09.640407 12166 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:09.640447 12166 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.640517 12166 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:09.640553 12166 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.645025 12166 rpc_server.cc:307] RPC server started. Bound to: 127.11.225.129:41297
I20260812 06:18:09.645975 12780 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.225.129:41297 every 8 connection(s)
I20260812 06:18:09.653877 12783 heartbeater.cc:344] Connected to a master server at 127.11.225.190:46597
I20260812 06:18:09.653998 12783 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:09.654217 12783 heartbeater.cc:507] Master 127.11.225.190:46597 requested a full tablet report, sending...
I20260812 06:18:09.654949 12569 ts_manager.cc:194] Registered new tserver with Master: 0467f871e49a4ea7a351bb3ae91d8e61 (127.11.225.129:41297)
I20260812 06:18:09.655118 12166 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009060154s
I20260812 06:18:09.655761 12569 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51646
I20260812 06:18:09.662689 12569 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51652:
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:09.672144 12720 tablet_service.cc:1511] Processing CreateTablet for tablet 10492a8e816d496584169b92fae6f433 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9dc7242e815646539e1371a6e1601dc7]), partition=
I20260812 06:18:09.672559 12720 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 10492a8e816d496584169b92fae6f433. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:09.675243 12798 tablet_bootstrap.cc:492] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Bootstrap starting.
I20260812 06:18:09.676134 12798 tablet_bootstrap.cc:654] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.677402 12798 tablet_bootstrap.cc:492] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: No bootstrap required, opened a new log
I20260812 06:18:09.677508 12798 ts_tablet_manager.cc:1403] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:09.677990 12798 raft_consensus.cc:359] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0467f871e49a4ea7a351bb3ae91d8e61" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 41297 } }
I20260812 06:18:09.678112 12798 raft_consensus.cc:385] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.678158 12798 raft_consensus.cc:740] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0467f871e49a4ea7a351bb3ae91d8e61, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.678311 12798 consensus_queue.cc:260] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [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: "0467f871e49a4ea7a351bb3ae91d8e61" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 41297 } }
I20260812 06:18:09.678409 12798 raft_consensus.cc:399] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.678455 12798 raft_consensus.cc:493] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.678514 12798 raft_consensus.cc:3060] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.679308 12798 raft_consensus.cc:515] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0467f871e49a4ea7a351bb3ae91d8e61" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 41297 } }
I20260812 06:18:09.679474 12798 leader_election.cc:304] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [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: 0467f871e49a4ea7a351bb3ae91d8e61; no voters: 
I20260812 06:18:09.679692 12798 leader_election.cc:290] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.679875 12804 raft_consensus.cc:2804] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.680091 12798 ts_tablet_manager.cc:1434] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:09.680117 12783 heartbeater.cc:499] Master 127.11.225.190:46597 was elected leader, sending a full tablet report...
I20260812 06:18:09.680143 12804 raft_consensus.cc:697] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 1 LEADER]: Becoming Leader. State: Replica: 0467f871e49a4ea7a351bb3ae91d8e61, State: Running, Role: LEADER
I20260812 06:18:09.680402 12804 consensus_queue.cc:237] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [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: "0467f871e49a4ea7a351bb3ae91d8e61" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 41297 } }
I20260812 06:18:09.681897 12569 catalog_manager.cc:5719] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0467f871e49a4ea7a351bb3ae91d8e61 (127.11.225.129). New cstate: current_term: 1 leader_uuid: "0467f871e49a4ea7a351bb3ae91d8e61" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0467f871e49a4ea7a351bb3ae91d8e61" member_type: VOTER last_known_addr { host: "127.11.225.129" port: 41297 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:09.742799 12166 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.017s	sys 0.006s
I20260812 06:18:09.896628 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushMRSOp(10492a8e816d496584169b92fae6f433): perf score=19.054940
I20260812 06:18:10.064587 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushMRSOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.168s	user 0.129s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1002,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42662,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:10.065294 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 20290830 bytes of WAL
I20260812 06:18:10.065555 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 2 log segments from log reader
I20260812 06:18:10.065618 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000001 (ops 1-6)
I20260812 06:18:10.065670 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000002 (ops 7-10)
I20260812 06:18:10.070770 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:10.071208 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.100106 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.029s	user 0.004s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.100596 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.120644 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.020s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.121282 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:10.340945 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.219s	user 0.140s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":605,"lbm_read_time_us":15658,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34028,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":333,"threads_started":5,"update_count":2500}
I20260812 06:18:10.341598 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433): 16411393 bytes on disk
I20260812 06:18:10.342051 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433) 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:18:10.342640 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:10.397387 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.055s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.397934 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.409866 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.410571 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:10.612846 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.202s	user 0.146s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1206,"lbm_read_time_us":14291,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32026,"lbm_writes_lt_1ms":543,"mutex_wait_us":556,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:10.613373 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=11.118625
I20260812 06:18:10.658584 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.045s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17971,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:10.659196 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.678440 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.019s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.679013 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.690364 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.690886 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:10.860960 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.170s	user 0.132s	sys 0.035s 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":241,"lbm_read_time_us":12558,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33631,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:10.861609 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=10.126437
I20260812 06:18:10.906242 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18832,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.907029 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:10.924453 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.017s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.925004 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.054788 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.130s	user 0.096s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":323,"lbm_read_time_us":8818,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23315,"lbm_writes_lt_1ms":443,"mutex_wait_us":659,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:18:11.057236 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=11.118625
I20260812 06:18:11.094187 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.036s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":16385,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.094864 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:11.105026 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.105508 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.236627 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.131s	user 0.100s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":10042,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24450,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:11.237242 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=10.126437
I20260812 06:18:11.296168 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.059s	user 0.021s	sys 0.032s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19664,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.296777 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:11.307775 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.308272 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.467590 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.159s	user 0.109s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":758,"lbm_read_time_us":11839,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24562,"lbm_writes_lt_1ms":443,"mutex_wait_us":318,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:18:11.468330 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=10.126437
I20260812 06:18:11.507802 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16480,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.508496 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:11.521883 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.522405 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushMRSOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.556324 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushMRSOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1534,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1544,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:11.556995 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 129320490 bytes of WAL
I20260812 06:18:11.557219 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 13 log segments from log reader
I20260812 06:18:11.557287 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000003 (ops 11-15)
I20260812 06:18:11.557344 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000004 (ops 16-20)
I20260812 06:18:11.557400 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000005 (ops 21-25)
I20260812 06:18:11.557441 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000006 (ops 26-30)
I20260812 06:18:11.557497 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000007 (ops 31-34)
I20260812 06:18:11.557520 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000008 (ops 35-39)
I20260812 06:18:11.557541 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000009 (ops 40-44)
I20260812 06:18:11.557583 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000010 (ops 45-48)
I20260812 06:18:11.557626 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000011 (ops 49-53)
I20260812 06:18:11.557667 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000012 (ops 54-58)
I20260812 06:18:11.557703 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000013 (ops 59-63)
I20260812 06:18:11.557740 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000014 (ops 64-68)
I20260812 06:18:11.557778 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000015 (ops 69-73)
I20260812 06:18:11.591598 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:18:11.592243 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=4.173312
I20260812 06:18:11.621186 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.029s	user 0.014s	sys 0.011s Metrics: {"bytes_written":6276941,"delete_count":0,"lbm_write_time_us":7759,"lbm_writes_lt_1ms":156,"mutex_wait_us":220,"reinsert_count":0,"update_count":765}
I20260812 06:18:11.621794 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.628429 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":2072,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:18:11.629015 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:11.844194 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.215s	user 0.159s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877287,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":636,"lbm_read_time_us":15998,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35304,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:11.844957 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:11.906972 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.062s	user 0.046s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21145,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.907610 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433): 483 bytes on disk
I20260812 06:18:11.908129 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.908648 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:11.919884 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4422,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.920347 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:12.105721 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.185s	user 0.139s	sys 0.045s 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":574,"lbm_read_time_us":14058,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30487,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":48128,"update_count":2500}
I20260812 06:18:12.106467 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=11.118625
I20260812 06:18:12.150123 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.043s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18738,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:12.150782 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.166013 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.166512 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.189543 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.023s	user 0.008s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3728,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.190142 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:12.369936 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.180s	user 0.119s	sys 0.060s 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":728,"lbm_read_time_us":14007,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28489,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:18:12.370504 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:12.433300 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.063s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25129,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.433799 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.444547 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.445348 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:12.612042 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.166s	user 0.115s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":433,"lbm_read_time_us":12958,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31779,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:18:12.612747 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=10.126437
I20260812 06:18:12.661463 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.049s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":22194,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.661990 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.688558 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.689078 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.700366 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.701056 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:12.866933 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.166s	user 0.129s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":546,"lbm_read_time_us":13114,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30763,"lbm_writes_lt_1ms":543,"mutex_wait_us":374,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:18:12.867662 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:12.920686 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.053s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24644,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.921304 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:12.941007 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.941545 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:13.107355 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.166s	user 0.117s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":398,"lbm_read_time_us":11214,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33334,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:13.108031 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:13.161275 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.053s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23153,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.161868 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:13.174319 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.174930 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushMRSOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:13.206545 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushMRSOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1528,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2073,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:13.207376 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 124710276 bytes of WAL
I20260812 06:18:13.207643 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 12 log segments from log reader
I20260812 06:18:13.207690 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000016 (ops 74-78)
I20260812 06:18:13.207721 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000017 (ops 79-83)
I20260812 06:18:13.207777 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000018 (ops 84-88)
I20260812 06:18:13.207824 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000019 (ops 89-93)
I20260812 06:18:13.207883 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000020 (ops 94-98)
I20260812 06:18:13.207940 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000021 (ops 99-103)
I20260812 06:18:13.207983 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000022 (ops 104-108)
I20260812 06:18:13.208021 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000023 (ops 109-113)
I20260812 06:18:13.208060 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000024 (ops 114-118)
I20260812 06:18:13.208101 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000025 (ops 119-123)
I20260812 06:18:13.208139 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000026 (ops 124-128)
I20260812 06:18:13.208177 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000027 (ops 129-133)
I20260812 06:18:13.236925 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:13.237425 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433): 491 bytes on disk
I20260812 06:18:13.238052 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":133,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.238734 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=3.181125
I20260812 06:18:13.256870 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4594953,"delete_count":0,"lbm_write_time_us":7487,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:18:13.257342 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 12018006 bytes of WAL
I20260812 06:18:13.257562 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 1 log segments from log reader
I20260812 06:18:13.257607 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000028 (ops 134-138)
I20260812 06:18:13.260105 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:13.260484 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:13.271878 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:18:13.272444 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:13.470921 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.198s	user 0.136s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":354,"lbm_read_time_us":13698,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43796,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:18:13.471609 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:13.520349 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.048s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21057,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.521015 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:13.539266 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.018s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":500}
I20260812 06:18:13.539773 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:13.712772 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.173s	user 0.134s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":10258,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35097,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:13.713467 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:13.775204 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.062s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22286,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:13.775776 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:13.787750 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.788558 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:13.975637 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.187s	user 0.128s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":723,"lbm_read_time_us":13046,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30999,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:18:13.976404 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:14.038147 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.062s	user 0.012s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21547,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.038780 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:14.050971 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.051620 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:14.242749 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.191s	user 0.126s	sys 0.065s 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":417,"lbm_read_time_us":14446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34531,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:18:14.243600 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:14.294903 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.051s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23216,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.295535 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:14.309883 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4725,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.310354 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:14.477272 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.167s	user 0.115s	sys 0.051s 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":365,"lbm_read_time_us":12253,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28147,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2500}
I20260812 06:18:14.477918 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:14.539417 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.061s	user 0.042s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.540043 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:14.552201 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.552721 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:14.739023 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.186s	user 0.109s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":13820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33698,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:14.739977 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=14.095187
I20260812 06:18:14.790952 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.051s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:14.791692 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:14.818950 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.027s	user 0.019s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.819522 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushMRSOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:14.832669 12166 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.090s	user 1.898s	sys 0.151s
I20260812 06:18:14.860205 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushMRSOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.040s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1506,"drs_written":1,"lbm_read_time_us":33,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1828,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:14.860975 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 121006699 bytes of WAL
I20260812 06:18:14.861218 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 12 log segments from log reader
I20260812 06:18:14.861282 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000029 (ops 139-143)
I20260812 06:18:14.861357 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000030 (ops 144-148)
I20260812 06:18:14.861413 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000031 (ops 149-153)
I20260812 06:18:14.861459 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000032 (ops 154-158)
I20260812 06:18:14.861496 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000033 (ops 159-162)
I20260812 06:18:14.861536 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000034 (ops 163-167)
I20260812 06:18:14.861577 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000035 (ops 168-172)
I20260812 06:18:14.861615 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000036 (ops 173-177)
I20260812 06:18:14.861654 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000037 (ops 178-182)
I20260812 06:18:14.861696 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000038 (ops 183-187)
I20260812 06:18:14.861735 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000039 (ops 188-192)
I20260812 06:18:14.861774 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000040 (ops 193-197)
I20260812 06:18:14.887040 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:14.887526 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433): 493 bytes on disk
I20260812 06:18:14.887988 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: UndoDeltaBlockGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.888587 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433): perf score=2.188937
I20260812 06:18:14.899925 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: FlushDeltaMemStoresOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.900491 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling LogGCOp(10492a8e816d496584169b92fae6f433): free 12017954 bytes of WAL
I20260812 06:18:14.900748 12686 log_reader.cc:385] T 10492a8e816d496584169b92fae6f433: removed 1 log segments from log reader
I20260812 06:18:14.900794 12686 log.cc:1079] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: Deleting log segment in path: /tmp/dist-test-taskw2hcS0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483667738-12166-0/minicluster-data/ts-0-root/wals/10492a8e816d496584169b92fae6f433/wal-000000041 (ops 198-202)
I20260812 06:18:14.903435 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: LogGCOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:14.903833 12784 maintenance_manager.cc:419] P 0467f871e49a4ea7a351bb3ae91d8e61: Scheduling MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433): perf score=1.000000
I20260812 06:18:14.911185 12166 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.002s	sys 0.000s
I20260812 06:18:14.911734 12166 tablet_server.cc:179] TabletServer@127.11.225.129:0 shutting down...
I20260812 06:18:15.047081 12686 maintenance_manager.cc:643] P 0467f871e49a4ea7a351bb3ae91d8e61: MajorDeltaCompactionOp(10492a8e816d496584169b92fae6f433) complete. Timing: real 0.143s	user 0.095s	sys 0.048s Metrics: {"cfile_cache_hit":532,"cfile_cache_hit_bytes":24774685,"cfile_cache_miss":101,"cfile_cache_miss_bytes":4102531,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":529,"lbm_read_time_us":2282,"lbm_reads_lt_1ms":113,"lbm_write_time_us":29870,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:15.047797 12166 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:15.048157 12166 tablet_replica.cc:333] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61: stopping tablet replica
I20260812 06:18:15.048333 12166 raft_consensus.cc:2243] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.048538 12166 raft_consensus.cc:2272] T 10492a8e816d496584169b92fae6f433 P 0467f871e49a4ea7a351bb3ae91d8e61 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.054524 12166 tablet_server.cc:196] TabletServer@127.11.225.129:0 shutdown complete.
I20260812 06:18:15.100243 12166 master.cc:562] Master@127.11.225.190:46597 shutting down...
I20260812 06:18:15.103534 12166 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.103773 12166 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.103864 12166 tablet_replica.cc:333] T 00000000000000000000000000000000 P fd9dd51b40ba4941bc51851e4c12ca28: stopping tablet replica
I20260812 06:18:15.116453 12166 master.cc:584] Master@127.11.225.190:46597 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5670 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11528 ms total)

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