[==========] 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:18.714949 19258 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.206.190:43511
I20260812 06:18:18.715794 19258 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:18.716323 19258 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.722023 19272 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:18.722051 19274 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:18.722085 19258 server_base.cc:1061] running on GCE node
W20260812 06:18:18.722301 19269 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:18.722791 19258 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.722896 19258 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:18.722935 19258 hybrid_clock.cc:648] HybridClock initialized: now 1786515498722933 us; error 0 us; skew 500 ppm
I20260812 06:18:18.724717 19258 webserver.cc:533] Webserver started at http://127.18.206.190:36263/ using document root <none> and password file <none>
I20260812 06:18:18.725277 19258 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.725360 19258 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.725590 19258 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.727286 19258 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/master-0-root/instance:
uuid: "2d9f120d29cc406cb7cb1ecd855cffb9"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-6zbq"
I20260812 06:18:18.730361 19258 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:18.732632 19281 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:18.733630 19258 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:18.733732 19258 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/master-0-root
uuid: "2d9f120d29cc406cb7cb1ecd855cffb9"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-6zbq"
I20260812 06:18:18.733816 19258 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-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:18.746850 19258 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.747308 19258 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:18.747426 19258 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.753870 19258 rpc_server.cc:307] RPC server started. Bound to: 127.18.206.190:43511
I20260812 06:18:18.753867 19362 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.206.190:43511 every 8 connection(s)
I20260812 06:18:18.755872 19363 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:18.760681 19363 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: Bootstrap starting.
I20260812 06:18:18.762799 19363 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:18.763569 19363 log.cc:826] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:18.764950 19363 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: No bootstrap required, opened a new log
I20260812 06:18:18.767480 19363 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER }
I20260812 06:18:18.767624 19363 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:18.767706 19363 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d9f120d29cc406cb7cb1ecd855cffb9, State: Initialized, Role: FOLLOWER
I20260812 06:18:18.768213 19363 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [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: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER }
I20260812 06:18:18.768345 19363 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:18.768407 19363 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:18.768520 19363 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:18.769176 19363 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER }
I20260812 06:18:18.769553 19363 leader_election.cc:304] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [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: 2d9f120d29cc406cb7cb1ecd855cffb9; no voters: 
I20260812 06:18:18.769832 19363 leader_election.cc:290] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:18.769930 19369 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:18.770145 19369 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 1 LEADER]: Becoming Leader. State: Replica: 2d9f120d29cc406cb7cb1ecd855cffb9, State: Running, Role: LEADER
I20260812 06:18:18.770555 19369 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [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: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER }
I20260812 06:18:18.770663 19363 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:18.772188 19373 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2d9f120d29cc406cb7cb1ecd855cffb9. Latest consensus state: current_term: 1 leader_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER } }
I20260812 06:18:18.772297 19373 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.772284 19370 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d9f120d29cc406cb7cb1ecd855cffb9" member_type: VOTER } }
I20260812 06:18:18.772384 19370 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.772640 19387 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:18.774755 19387 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:18.775050 19258 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:18.778728 19387 catalog_manager.cc:1383] Generated new cluster ID: af47968b8e7148728f8daa5347b70b4a
I20260812 06:18:18.778786 19387 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:18.803304 19387 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:18.804293 19387 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:18.818282 19387 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: Generated new TSK 0
I20260812 06:18:18.818796 19387 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:18.839490 19258 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.841946 19406 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:18.841995 19405 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:18.842099 19408 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:18.842012 19258 server_base.cc:1061] running on GCE node
I20260812 06:18:18.842331 19258 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.842401 19258 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:18.842428 19258 hybrid_clock.cc:648] HybridClock initialized: now 1786515498842428 us; error 0 us; skew 500 ppm
I20260812 06:18:18.843255 19258 webserver.cc:533] Webserver started at http://127.18.206.129:41299/ using document root <none> and password file <none>
I20260812 06:18:18.843402 19258 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.843452 19258 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.843523 19258 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.843861 19258 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/instance:
uuid: "bdb6d66721f745f4a843df2964f07771"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-6zbq"
I20260812 06:18:18.845166 19258 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:18.846019 19421 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:18.846256 19258 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:18.846321 19258 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root
uuid: "bdb6d66721f745f4a843df2964f07771"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-6zbq"
I20260812 06:18:18.846412 19258 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-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:18.894053 19258 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.894498 19258 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.894925 19258 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:18.895709 19258 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:18.895761 19258 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.895798 19258 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:18.895834 19258 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.901819 19258 rpc_server.cc:307] RPC server started. Bound to: 127.18.206.129:42623
I20260812 06:18:18.901856 19534 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.206.129:42623 every 8 connection(s)
I20260812 06:18:18.912853 19535 heartbeater.cc:344] Connected to a master server at 127.18.206.190:43511
I20260812 06:18:18.913045 19535 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:18.913446 19535 heartbeater.cc:507] Master 127.18.206.190:43511 requested a full tablet report, sending...
I20260812 06:18:18.914811 19258 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012423639s
I20260812 06:18:18.914992 19302 ts_manager.cc:194] Registered new tserver with Master: bdb6d66721f745f4a843df2964f07771 (127.18.206.129:42623)
I20260812 06:18:18.916391 19302 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43958
I20260812 06:18:18.923697 19302 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43962:
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:18.936830 19477 tablet_service.cc:1511] Processing CreateTablet for tablet 33460ab026884ca2a8c5761e9bdbe24c (DEFAULT_TABLE table=heavy-update-compaction-test [id=a82c47385dac43b3bf4bd6a61fbc137e]), partition=
I20260812 06:18:18.937255 19477 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 33460ab026884ca2a8c5761e9bdbe24c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:18.939316 19551 tablet_bootstrap.cc:492] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Bootstrap starting.
I20260812 06:18:18.940137 19551 tablet_bootstrap.cc:654] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:18.941110 19551 tablet_bootstrap.cc:492] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: No bootstrap required, opened a new log
I20260812 06:18:18.941191 19551 ts_tablet_manager.cc:1403] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:18.941536 19551 raft_consensus.cc:359] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bdb6d66721f745f4a843df2964f07771" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 42623 } }
I20260812 06:18:18.941625 19551 raft_consensus.cc:385] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:18.941658 19551 raft_consensus.cc:740] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bdb6d66721f745f4a843df2964f07771, State: Initialized, Role: FOLLOWER
I20260812 06:18:18.941779 19551 consensus_queue.cc:260] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [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: "bdb6d66721f745f4a843df2964f07771" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 42623 } }
I20260812 06:18:18.941869 19551 raft_consensus.cc:399] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:18.941906 19551 raft_consensus.cc:493] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:18.941954 19551 raft_consensus.cc:3060] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:18.942595 19551 raft_consensus.cc:515] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bdb6d66721f745f4a843df2964f07771" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 42623 } }
I20260812 06:18:18.942708 19551 leader_election.cc:304] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [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: bdb6d66721f745f4a843df2964f07771; no voters: 
I20260812 06:18:18.942888 19551 leader_election.cc:290] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:18.943012 19553 raft_consensus.cc:2804] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:18.943214 19553 raft_consensus.cc:697] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 1 LEADER]: Becoming Leader. State: Replica: bdb6d66721f745f4a843df2964f07771, State: Running, Role: LEADER
I20260812 06:18:18.943225 19551 ts_tablet_manager.cc:1434] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:18.943414 19553 consensus_queue.cc:237] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [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: "bdb6d66721f745f4a843df2964f07771" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 42623 } }
I20260812 06:18:18.943569 19535 heartbeater.cc:499] Master 127.18.206.190:43511 was elected leader, sending a full tablet report...
I20260812 06:18:18.947022 19302 catalog_manager.cc:5719] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 reported cstate change: term changed from 0 to 1, leader changed from <none> to bdb6d66721f745f4a843df2964f07771 (127.18.206.129). New cstate: current_term: 1 leader_uuid: "bdb6d66721f745f4a843df2964f07771" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bdb6d66721f745f4a843df2964f07771" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 42623 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:18.998968 19258 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.006s	sys 0.018s
I20260812 06:18:19.152875 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=23.023690
I20260812 06:18:19.318186 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.165s	user 0.115s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":292,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":678,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41869,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":207,"threads_started":1,"update_count":1500}
I20260812 06:18:19.319466 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling LogGCOp(33460ab026884ca2a8c5761e9bdbe24c): free 20743880 bytes of WAL
I20260812 06:18:19.319808 19430 log_reader.cc:385] T 33460ab026884ca2a8c5761e9bdbe24c: removed 2 log segments from log reader
I20260812 06:18:19.319883 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000001 (ops 1-6)
I20260812 06:18:19.319941 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000002 (ops 7-11)
I20260812 06:18:19.324918 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: LogGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:19.325260 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c): 20513813 bytes on disk
I20260812 06:18:19.325862 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.326272 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:19.339222 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.339677 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:19.476318 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.137s	user 0.102s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":8977,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23453,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":252,"threads_started":5,"update_count":2000}
I20260812 06:18:19.476804 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:19.515334 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.038s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13084,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.515765 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:19.525472 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.525909 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:19.638356 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.112s	user 0.100s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":189,"lbm_read_time_us":9403,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19417,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:18:19.638841 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:19.678107 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.039s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12946,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.678581 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:19.693078 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.693570 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:19.818380 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":9291,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24879,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:18:19.818848 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:19.867627 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.049s	user 0.028s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18681,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.868108 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:19.877600 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.877952 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.014060 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.136s	user 0.096s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":83,"lbm_read_time_us":10078,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23456,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":42368,"update_count":2000}
I20260812 06:18:20.014510 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:20.052170 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15585,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.052611 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.157642 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.105s	user 0.081s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":142,"lbm_read_time_us":6997,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20170,"lbm_writes_lt_1ms":343,"mutex_wait_us":34,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":1500}
I20260812 06:18:20.158186 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:20.200948 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.043s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14750,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.201416 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:20.210529 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.210971 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.322872 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.111s	user 0.087s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":7272,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21963,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:18:20.323341 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:20.366889 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.043s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14288,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.367427 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:20.377101 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.377564 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.519093 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.141s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":913,"lbm_read_time_us":9492,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23339,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:20.519579 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=10.126437
I20260812 06:18:20.564507 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.045s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15747,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.565009 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:20.575652 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.576059 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.602939 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.027s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1006,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:20.603868 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling LogGCOp(33460ab026884ca2a8c5761e9bdbe24c): free 129320495 bytes of WAL
I20260812 06:18:20.604130 19430 log_reader.cc:385] T 33460ab026884ca2a8c5761e9bdbe24c: removed 13 log segments from log reader
I20260812 06:18:20.604193 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000003 (ops 12-16)
I20260812 06:18:20.604233 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000004 (ops 17-21)
I20260812 06:18:20.604265 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000005 (ops 22-26)
I20260812 06:18:20.604291 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000006 (ops 27-31)
I20260812 06:18:20.604312 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000007 (ops 32-36)
I20260812 06:18:20.604333 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000008 (ops 37-40)
I20260812 06:18:20.604364 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000009 (ops 41-45)
I20260812 06:18:20.604390 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000010 (ops 46-50)
I20260812 06:18:20.604417 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000011 (ops 51-54)
I20260812 06:18:20.604444 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000012 (ops 55-59)
I20260812 06:18:20.604465 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000013 (ops 60-64)
I20260812 06:18:20.604485 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000014 (ops 65-69)
I20260812 06:18:20.604512 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000015 (ops 70-74)
I20260812 06:18:20.631476 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: LogGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:18:20.631836 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c): 482 bytes on disk
I20260812 06:18:20.632239 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.632754 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=3.181125
I20260812 06:18:20.644532 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":4563,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:18:20.644878 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.196750
I20260812 06:18:20.659222 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":2702,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:20.659680 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:20.856374 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.197s	user 0.124s	sys 0.066s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2935,"lbm_read_time_us":13408,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33147,"lbm_writes_lt_1ms":643,"mutex_wait_us":1773,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:18:20.856850 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:20.919616 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.063s	user 0.029s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.920120 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:20.934513 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.934940 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:21.095144 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.160s	user 0.103s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":11191,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28793,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45824,"update_count":2500}
I20260812 06:18:21.095618 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=11.118625
I20260812 06:18:21.139169 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18712,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:21.139647 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:21.155798 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.156213 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:21.164775 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3242,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.165132 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:21.331655 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.166s	user 0.099s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":687,"lbm_read_time_us":9119,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26541,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:21.332155 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:21.385172 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.053s	user 0.018s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25474,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.385686 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:21.397234 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.397699 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:21.551585 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.154s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":445,"lbm_read_time_us":8424,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29146,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":940672,"update_count":2500}
I20260812 06:18:21.552117 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:21.596671 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.044s	user 0.014s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17800,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.597072 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:21.606873 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.607488 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:21.757241 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.150s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":11215,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26299,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:18:21.758172 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:21.803195 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.045s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18463,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.803705 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:21.818251 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.818783 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:21.956615 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.138s	user 0.111s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":138,"lbm_read_time_us":11345,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25976,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:21.957158 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=11.118625
I20260812 06:18:21.992268 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.035s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12594661,"delete_count":0,"lbm_write_time_us":14712,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:18:21.992888 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.003468 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":96,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":465}
I20260812 06:18:22.003943 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:22.055030 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.051s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":148,"dirs.run_wall_time_us":856,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2084,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:22.055821 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling LogGCOp(33460ab026884ca2a8c5761e9bdbe24c): free 132118297 bytes of WAL
I20260812 06:18:22.056053 19430 log_reader.cc:385] T 33460ab026884ca2a8c5761e9bdbe24c: removed 13 log segments from log reader
I20260812 06:18:22.056128 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000016 (ops 75-78)
I20260812 06:18:22.056159 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000017 (ops 79-83)
I20260812 06:18:22.056190 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000018 (ops 84-88)
I20260812 06:18:22.056222 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000019 (ops 89-93)
I20260812 06:18:22.056244 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000020 (ops 94-98)
I20260812 06:18:22.056277 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000021 (ops 99-102)
I20260812 06:18:22.056309 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000022 (ops 103-107)
I20260812 06:18:22.056340 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000023 (ops 108-112)
I20260812 06:18:22.056373 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000024 (ops 113-117)
I20260812 06:18:22.056406 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000025 (ops 118-122)
I20260812 06:18:22.056437 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000026 (ops 123-126)
I20260812 06:18:22.056468 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000027 (ops 127-131)
I20260812 06:18:22.056500 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000028 (ops 132-136)
I20260812 06:18:22.081324 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: LogGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:22.081789 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=7.149875
I20260812 06:18:22.100230 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":7457,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:22.100760 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.115509 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5224,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.115960 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c): 493 bytes on disk
I20260812 06:18:22.116382 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: UndoDeltaBlockGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.116861 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:22.298426 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.181s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":494,"lbm_read_time_us":13890,"lbm_reads_lt_1ms":766,"lbm_write_time_us":35500,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:18:22.298868 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=18.063937
I20260812 06:18:22.346586 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.047s	user 0.027s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":20094,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.347069 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.362268 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.364125 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:22.511644 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.147s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":10055,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30639,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3000}
I20260812 06:18:22.512094 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:22.555634 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.043s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:22.556180 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.568178 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.568698 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:22.716531 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.148s	user 0.110s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":583,"lbm_read_time_us":9776,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26147,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.717049 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:22.755147 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.038s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16843,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.755640 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:22.900027 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.144s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":182,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23865,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:22.902585 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=11.118625
I20260812 06:18:22.942901 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12963878,"delete_count":0,"lbm_write_time_us":17075,"lbm_writes_lt_1ms":319,"reinsert_count":0,"update_count":1580}
I20260812 06:18:22.943354 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.953836 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3856510,"delete_count":0,"lbm_write_time_us":3505,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:22.954265 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:22.962927 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3306,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.963268 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:23.131412 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.168s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815788,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":227,"lbm_read_time_us":10005,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27842,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:23.131937 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=14.095187
I20260812 06:18:23.178781 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.047s	user 0.040s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19027,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.179307 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:23.194133 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.194849 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:23.331357 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: MajorDeltaCompactionOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.136s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":8498,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26061,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:23.332019 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=11.118625
I20260812 06:18:23.381286 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.049s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20525,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.381798 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:23.390233 19258 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.391s	user 1.642s	sys 0.099s
I20260812 06:18:23.391640 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.392040 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=2.188937
I20260812 06:18:23.405145 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushDeltaMemStoresOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5220,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.405550 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c): perf score=1.000000
I20260812 06:18:23.445632 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: FlushMRSOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.040s	user 0.035s	sys 0.004s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1032,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2772,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:23.446221 19536 maintenance_manager.cc:419] P bdb6d66721f745f4a843df2964f07771: Scheduling LogGCOp(33460ab026884ca2a8c5761e9bdbe24c): free 129773852 bytes of WAL
I20260812 06:18:23.446295 19258 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.001s	sys 0.000s
I20260812 06:18:23.446481 19430 log_reader.cc:385] T 33460ab026884ca2a8c5761e9bdbe24c: removed 13 log segments from log reader
I20260812 06:18:23.446523 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000029 (ops 137-141)
I20260812 06:18:23.446553 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000030 (ops 142-146)
I20260812 06:18:23.446599 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000031 (ops 147-151)
I20260812 06:18:23.446633 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000032 (ops 152-156)
I20260812 06:18:23.446664 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000033 (ops 157-160)
I20260812 06:18:23.446695 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000034 (ops 161-165)
I20260812 06:18:23.446727 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000035 (ops 166-170)
I20260812 06:18:23.446758 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000036 (ops 171-175)
I20260812 06:18:23.446789 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000037 (ops 176-180)
I20260812 06:18:23.446821 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000038 (ops 181-185)
I20260812 06:18:23.446852 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000039 (ops 186-190)
I20260812 06:18:23.446898 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000040 (ops 191-195)
I20260812 06:18:23.446972 19430 log.cc:1079] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/33460ab026884ca2a8c5761e9bdbe24c/wal-000000041 (ops 196-200)
I20260812 06:18:23.447005 19258 tablet_server.cc:179] TabletServer@127.18.206.129:0 shutting down...
I20260812 06:18:23.468942 19430 maintenance_manager.cc:643] P bdb6d66721f745f4a843df2964f07771: LogGCOp(33460ab026884ca2a8c5761e9bdbe24c) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:18:23.469369 19258 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:23.469655 19258 tablet_replica.cc:333] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771: stopping tablet replica
I20260812 06:18:23.469841 19258 raft_consensus.cc:2243] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:23.470031 19258 raft_consensus.cc:2272] T 33460ab026884ca2a8c5761e9bdbe24c P bdb6d66721f745f4a843df2964f07771 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:23.483598 19258 tablet_server.cc:196] TabletServer@127.18.206.129:0 shutdown complete.
I20260812 06:18:23.487785 19258 master.cc:562] Master@127.18.206.190:43511 shutting down...
I20260812 06:18:23.490688 19258 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:23.490813 19258 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:23.490882 19258 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2d9f120d29cc406cb7cb1ecd855cffb9: stopping tablet replica
I20260812 06:18:23.502772 19258 master.cc:584] Master@127.18.206.190:43511 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4858 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:23.581470 19258 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.206.190:46121
I20260812 06:18:23.581817 19258 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.583588 19586 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:23.583663 19588 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:23.583786 19258 server_base.cc:1061] running on GCE node
W20260812 06:18:23.583789 19582 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:23.584034 19258 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.584082 19258 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:23.584096 19258 hybrid_clock.cc:648] HybridClock initialized: now 1786515503584097 us; error 0 us; skew 500 ppm
I20260812 06:18:23.584906 19258 webserver.cc:533] Webserver started at http://127.18.206.190:40687/ using document root <none> and password file <none>
I20260812 06:18:23.585049 19258 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.585098 19258 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.585186 19258 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.585541 19258 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/master-0-root/instance:
uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6zbq"
I20260812 06:18:23.587006 19258 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:23.587858 19600 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:23.588064 19258 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.588127 19258 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/master-0-root
uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6zbq"
I20260812 06:18:23.588217 19258 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-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:23.611603 19258 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.611891 19258 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.615630 19258 rpc_server.cc:307] RPC server started. Bound to: 127.18.206.190:46121
I20260812 06:18:23.619457 19703 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.206.190:46121 every 8 connection(s)
I20260812 06:18:23.619836 19707 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:23.621461 19707 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa: Bootstrap starting.
I20260812 06:18:23.622169 19707 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.623037 19707 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa: No bootstrap required, opened a new log
I20260812 06:18:23.623383 19707 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER }
I20260812 06:18:23.623462 19707 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.623485 19707 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6e8d0ae17e2b48b18bdbe21ecf6345fa, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.623608 19707 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [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: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER }
I20260812 06:18:23.623693 19707 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.623723 19707 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.623754 19707 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.624341 19707 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER }
I20260812 06:18:23.624449 19707 leader_election.cc:304] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [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: 6e8d0ae17e2b48b18bdbe21ecf6345fa; no voters: 
I20260812 06:18:23.624585 19707 leader_election.cc:290] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.624696 19714 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.624909 19714 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 1 LEADER]: Becoming Leader. State: Replica: 6e8d0ae17e2b48b18bdbe21ecf6345fa, State: Running, Role: LEADER
I20260812 06:18:23.624977 19707 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:23.625042 19714 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [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: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER }
I20260812 06:18:23.625447 19715 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER } }
I20260812 06:18:23.625473 19716 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6e8d0ae17e2b48b18bdbe21ecf6345fa. Latest consensus state: current_term: 1 leader_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e8d0ae17e2b48b18bdbe21ecf6345fa" member_type: VOTER } }
I20260812 06:18:23.625608 19716 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.625849 19715 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.626070 19723 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:23.626977 19723 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:23.627132 19258 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:23.628692 19723 catalog_manager.cc:1383] Generated new cluster ID: 2a41fd1019774db891c191e32844381e
I20260812 06:18:23.628749 19723 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:23.646193 19723 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:23.646687 19723 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:23.651867 19723 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa: Generated new TSK 0
I20260812 06:18:23.651993 19723 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:23.659183 19258 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.660684 19747 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:23.660766 19748 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:23.660806 19258 server_base.cc:1061] running on GCE node
W20260812 06:18:23.660807 19754 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:23.661084 19258 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.661139 19258 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:23.661158 19258 hybrid_clock.cc:648] HybridClock initialized: now 1786515503661158 us; error 0 us; skew 500 ppm
I20260812 06:18:23.661902 19258 webserver.cc:533] Webserver started at http://127.18.206.129:39459/ using document root <none> and password file <none>
I20260812 06:18:23.662045 19258 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.662089 19258 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.662165 19258 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.662530 19258 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/instance:
uuid: "503f1ca82bef400888bd99eb85e61963"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6zbq"
I20260812 06:18:23.663822 19258 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.664672 19761 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:23.664870 19258 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.664933 19258 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root
uuid: "503f1ca82bef400888bd99eb85e61963"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6zbq"
I20260812 06:18:23.664996 19258 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-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:23.695564 19258 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.695829 19258 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.696069 19258 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:23.696465 19258 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:23.696499 19258 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.696538 19258 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:23.696566 19258 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.700366 19258 rpc_server.cc:307] RPC server started. Bound to: 127.18.206.129:46127
I20260812 06:18:23.701254 19876 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.206.129:46127 every 8 connection(s)
I20260812 06:18:23.705135 19877 heartbeater.cc:344] Connected to a master server at 127.18.206.190:46121
I20260812 06:18:23.705231 19877 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:23.705415 19877 heartbeater.cc:507] Master 127.18.206.190:46121 requested a full tablet report, sending...
I20260812 06:18:23.705989 19634 ts_manager.cc:194] Registered new tserver with Master: 503f1ca82bef400888bd99eb85e61963 (127.18.206.129:46127)
I20260812 06:18:23.706482 19258 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005518427s
I20260812 06:18:23.706715 19634 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38936
I20260812 06:18:23.712102 19634 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38948:
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:23.719465 19812 tablet_service.cc:1511] Processing CreateTablet for tablet 20946de226064f62880b99591811c687 (DEFAULT_TABLE table=heavy-update-compaction-test [id=10ad3d628d1c4812b87729dc17bbe290]), partition=
I20260812 06:18:23.719681 19812 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 20946de226064f62880b99591811c687. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:23.721374 19900 tablet_bootstrap.cc:492] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Bootstrap starting.
I20260812 06:18:23.722262 19900 tablet_bootstrap.cc:654] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.724444 19900 tablet_bootstrap.cc:492] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: No bootstrap required, opened a new log
I20260812 06:18:23.724512 19900 ts_tablet_manager.cc:1403] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Time spent bootstrapping tablet: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:18:23.724884 19900 raft_consensus.cc:359] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "503f1ca82bef400888bd99eb85e61963" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 46127 } }
I20260812 06:18:23.724977 19900 raft_consensus.cc:385] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.725003 19900 raft_consensus.cc:740] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 503f1ca82bef400888bd99eb85e61963, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.725126 19900 consensus_queue.cc:260] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [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: "503f1ca82bef400888bd99eb85e61963" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 46127 } }
I20260812 06:18:23.725217 19900 raft_consensus.cc:399] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.725260 19900 raft_consensus.cc:493] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.725306 19900 raft_consensus.cc:3060] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.725977 19900 raft_consensus.cc:515] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "503f1ca82bef400888bd99eb85e61963" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 46127 } }
I20260812 06:18:23.726096 19900 leader_election.cc:304] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [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: 503f1ca82bef400888bd99eb85e61963; no voters: 
I20260812 06:18:23.726261 19900 leader_election.cc:290] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.726387 19903 raft_consensus.cc:2804] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.726542 19903 raft_consensus.cc:697] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 1 LEADER]: Becoming Leader. State: Replica: 503f1ca82bef400888bd99eb85e61963, State: Running, Role: LEADER
I20260812 06:18:23.726589 19900 ts_tablet_manager.cc:1434] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.726629 19877 heartbeater.cc:499] Master 127.18.206.190:46121 was elected leader, sending a full tablet report...
I20260812 06:18:23.726783 19903 consensus_queue.cc:237] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [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: "503f1ca82bef400888bd99eb85e61963" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 46127 } }
I20260812 06:18:23.727931 19634 catalog_manager.cc:5719] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 reported cstate change: term changed from 0 to 1, leader changed from <none> to 503f1ca82bef400888bd99eb85e61963 (127.18.206.129). New cstate: current_term: 1 leader_uuid: "503f1ca82bef400888bd99eb85e61963" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "503f1ca82bef400888bd99eb85e61963" member_type: VOTER last_known_addr { host: "127.18.206.129" port: 46127 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:23.781564 19258 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.017s	sys 0.004s
I20260812 06:18:23.951656 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushMRSOp(20946de226064f62880b99591811c687): perf score=23.023690
I20260812 06:18:24.107175 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushMRSOp(20946de226064f62880b99591811c687) complete. Timing: real 0.155s	user 0.111s	sys 0.040s Metrics: {"bytes_written":13045918,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":748,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39040,"lbm_writes_lt_1ms":975,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"update_count":1590}
I20260812 06:18:24.107990 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling LogGCOp(20946de226064f62880b99591811c687): free 32761802 bytes of WAL
I20260812 06:18:24.108225 19775 log_reader.cc:385] T 20946de226064f62880b99591811c687: removed 3 log segments from log reader
I20260812 06:18:24.108279 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000001 (ops 1-6)
I20260812 06:18:24.108319 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000002 (ops 7-11)
I20260812 06:18:24.108353 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000003 (ops 12-16)
I20260812 06:18:24.115561 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: LogGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:24.115880 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:24.132910 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.017s	user 0.000s	sys 0.012s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5420,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:24.133245 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:24.141631 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3193,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.141943 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:24.303484 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.161s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":258,"lbm_read_time_us":11820,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27406,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":305,"threads_started":5,"update_count":2500}
I20260812 06:18:24.303915 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling UndoDeltaBlockGCOp(20946de226064f62880b99591811c687): 24616238 bytes on disk
I20260812 06:18:24.304282 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: UndoDeltaBlockGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.304709 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:24.355273 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.050s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22974,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.355722 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:24.372381 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.372771 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:24.510493 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.138s	user 0.100s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":9143,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24063,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:24.514927 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:24.574748 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.057s	user 0.019s	sys 0.031s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22871,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.575287 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:24.590062 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.590507 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:24.795084 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.204s	user 0.156s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856650,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":77,"lbm_read_time_us":12535,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31490,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:24.795644 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=18.063937
I20260812 06:18:24.847200 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.051s	user 0.038s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22660,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:24.847596 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.001070 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.153s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24856537,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":518,"lbm_read_time_us":11434,"lbm_reads_lt_1ms":563,"lbm_write_time_us":24061,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:25.001585 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:25.050026 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.048s	user 0.016s	sys 0.029s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17308,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.050521 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.059892 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.060238 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.218933 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.159s	user 0.093s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856650,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":11812,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24960,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:18:25.219517 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=11.118625
I20260812 06:18:25.251587 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.032s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12928,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.252027 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.277249 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.025s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.277760 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.287093 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.287453 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushMRSOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.315665 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushMRSOp(20946de226064f62880b99591811c687) complete. Timing: real 0.028s	user 0.020s	sys 0.006s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":979,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1305,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":1280}
I20260812 06:18:25.316358 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling UndoDeltaBlockGCOp(20946de226064f62880b99591811c687): 472 bytes on disk
I20260812 06:18:25.316726 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: UndoDeltaBlockGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.317152 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.479746 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.162s	user 0.120s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856764,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":165,"lbm_read_time_us":10141,"lbm_reads_lt_1ms":565,"lbm_write_time_us":28089,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.480283 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling LogGCOp(20946de226064f62880b99591811c687): free 112692368 bytes of WAL
I20260812 06:18:25.480487 19775 log_reader.cc:385] T 20946de226064f62880b99591811c687: removed 11 log segments from log reader
I20260812 06:18:25.480526 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000004 (ops 17-21)
I20260812 06:18:25.480559 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000005 (ops 22-26)
I20260812 06:18:25.480641 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000006 (ops 27-31)
I20260812 06:18:25.480676 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000007 (ops 32-36)
I20260812 06:18:25.480697 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000008 (ops 37-41)
I20260812 06:18:25.480741 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000009 (ops 42-46)
I20260812 06:18:25.480790 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000010 (ops 47-51)
I20260812 06:18:25.480821 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000011 (ops 52-56)
I20260812 06:18:25.480863 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000012 (ops 57-61)
I20260812 06:18:25.480894 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000013 (ops 62-66)
I20260812 06:18:25.480935 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000014 (ops 67-71)
I20260812 06:18:25.505472 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: LogGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:25.505990 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=15.087375
I20260812 06:18:25.550105 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19465,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:25.550631 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.576951 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.026s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.577387 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.586829 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.587248 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.768710 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.181s	user 0.113s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959171,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":284,"lbm_read_time_us":12553,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31285,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:25.769531 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:25.821409 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.052s	user 0.042s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.821905 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:25.831647 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.832021 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:25.992321 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.160s	user 0.094s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":125,"lbm_read_time_us":11237,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24494,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:18:25.993016 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:26.051458 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.058s	user 0.020s	sys 0.037s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21003,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.051976 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.066407 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.066828 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:26.245621 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.179s	user 0.130s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":872,"lbm_read_time_us":12705,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27774,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:26.246198 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:26.292567 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.046s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18703,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.292980 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.302525 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.303102 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:26.459262 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.156s	user 0.083s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":125,"lbm_read_time_us":9112,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25477,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:26.459882 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:26.508687 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.049s	user 0.021s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23681,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.509318 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.536201 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.027s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.536676 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.560235 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.023s	user 0.003s	sys 0.019s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.560803 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:26.734081 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.173s	user 0.130s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959183,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":232,"lbm_read_time_us":12135,"lbm_reads_lt_1ms":673,"lbm_write_time_us":28619,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:18:26.734987 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:26.791772 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.056s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20160,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.792287 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.806479 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.806885 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushMRSOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:26.845624 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushMRSOp(20946de226064f62880b99591811c687) complete. Timing: real 0.039s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":147,"dirs.run_wall_time_us":979,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1888,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:26.846258 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling LogGCOp(20946de226064f62880b99591811c687): free 133024394 bytes of WAL
I20260812 06:18:26.846480 19775 log_reader.cc:385] T 20946de226064f62880b99591811c687: removed 13 log segments from log reader
I20260812 06:18:26.846526 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000015 (ops 72-76)
I20260812 06:18:26.846552 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000016 (ops 77-81)
I20260812 06:18:26.846580 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000017 (ops 82-86)
I20260812 06:18:26.846613 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000018 (ops 87-91)
I20260812 06:18:26.846638 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000019 (ops 92-96)
I20260812 06:18:26.846670 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000020 (ops 97-100)
I20260812 06:18:26.846704 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000021 (ops 101-105)
I20260812 06:18:26.846735 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000022 (ops 106-110)
I20260812 06:18:26.846767 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000023 (ops 111-115)
I20260812 06:18:26.846799 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000024 (ops 116-120)
I20260812 06:18:26.846832 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000025 (ops 121-125)
I20260812 06:18:26.846863 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000026 (ops 126-130)
I20260812 06:18:26.846894 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000027 (ops 131-135)
I20260812 06:18:26.871655 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: LogGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:26.872103 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling UndoDeltaBlockGCOp(20946de226064f62880b99591811c687): 492 bytes on disk
I20260812 06:18:26.872542 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: UndoDeltaBlockGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.873041 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=3.181125
I20260812 06:18:26.892102 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.019s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6511,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:26.892462 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:26.900763 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3178,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.901129 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:27.120292 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.219s	user 0.143s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061705,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":184,"lbm_read_time_us":13908,"lbm_reads_lt_1ms":774,"lbm_write_time_us":32628,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:18:27.120842 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=18.063937
I20260812 06:18:27.186807 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.065s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":23867,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:27.187279 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:27.196805 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.197341 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:27.388527 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.191s	user 0.131s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959066,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":12551,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32840,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:18:27.388998 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:27.445453 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.056s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21056,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.445919 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:27.455614 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.456208 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:27.608045 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.152s	user 0.101s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":480,"lbm_read_time_us":10339,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24989,"lbm_writes_lt_1ms":543,"mutex_wait_us":242,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:27.608614 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:27.656759 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.048s	user 0.026s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16776,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.657291 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:27.672952 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.674671 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:27.835770 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.161s	user 0.134s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":11646,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26023,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:18:27.836364 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:27.895905 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.059s	user 0.047s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24407,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.896358 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:27.906710 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.907202 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:28.073066 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.166s	user 0.116s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":11128,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29175,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:18:28.073676 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:28.131984 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.058s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19397,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.132464 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=2.188937
I20260812 06:18:28.142175 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.142642 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushMRSOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:28.170374 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushMRSOp(20946de226064f62880b99591811c687) complete. Timing: real 0.028s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1037,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1511,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:28.171200 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling UndoDeltaBlockGCOp(20946de226064f62880b99591811c687): 447 bytes on disk
I20260812 06:18:28.171588 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: UndoDeltaBlockGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.172086 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling MajorDeltaCompactionOp(20946de226064f62880b99591811c687): perf score=1.000000
I20260812 06:18:28.315438 19258 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.534s	user 1.576s	sys 0.204s
I20260812 06:18:28.323592 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: MajorDeltaCompactionOp(20946de226064f62880b99591811c687) complete. Timing: real 0.151s	user 0.089s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":10536,"lbm_reads_lt_1ms":560,"lbm_write_time_us":24252,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:18:28.324048 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling LogGCOp(20946de226064f62880b99591811c687): free 120553636 bytes of WAL
I20260812 06:18:28.324277 19775 log_reader.cc:385] T 20946de226064f62880b99591811c687: removed 12 log segments from log reader
I20260812 06:18:28.324342 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000028 (ops 136-140)
I20260812 06:18:28.324389 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000029 (ops 141-144)
I20260812 06:18:28.324435 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000030 (ops 145-149)
I20260812 06:18:28.324473 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000031 (ops 150-154)
I20260812 06:18:28.324509 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000032 (ops 155-158)
I20260812 06:18:28.324543 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000033 (ops 159-163)
I20260812 06:18:28.324579 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000034 (ops 164-168)
I20260812 06:18:28.324612 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000035 (ops 169-173)
I20260812 06:18:28.324649 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000036 (ops 174-178)
I20260812 06:18:28.324678 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000037 (ops 179-183)
I20260812 06:18:28.324712 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000038 (ops 184-188)
I20260812 06:18:28.324746 19775 log.cc:1079] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: Deleting log segment in path: /tmp/dist-test-taskch1qeN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498705055-19258-0/minicluster-data/ts-0-root/wals/20946de226064f62880b99591811c687/wal-000000039 (ops 189-193)
I20260812 06:18:28.350872 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: LogGCOp(20946de226064f62880b99591811c687) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:28.351274 19878 maintenance_manager.cc:419] P 503f1ca82bef400888bd99eb85e61963: Scheduling FlushDeltaMemStoresOp(20946de226064f62880b99591811c687): perf score=14.095187
I20260812 06:18:28.376233 19258 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.001s	sys 0.003s
I20260812 06:18:28.376784 19258 tablet_server.cc:179] TabletServer@127.18.206.129:0 shutting down...
I20260812 06:18:28.390136 19775 maintenance_manager.cc:643] P 503f1ca82bef400888bd99eb85e61963: FlushDeltaMemStoresOp(20946de226064f62880b99591811c687) complete. Timing: real 0.039s	user 0.018s	sys 0.017s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":16974,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.390623 19258 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:28.390823 19258 tablet_replica.cc:333] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963: stopping tablet replica
I20260812 06:18:28.390954 19258 raft_consensus.cc:2243] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.391106 19258 raft_consensus.cc:2272] T 20946de226064f62880b99591811c687 P 503f1ca82bef400888bd99eb85e61963 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.404066 19258 tablet_server.cc:196] TabletServer@127.18.206.129:0 shutdown complete.
I20260812 06:18:28.406965 19258 master.cc:562] Master@127.18.206.190:46121 shutting down...
I20260812 06:18:28.410072 19258 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.410200 19258 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.410262 19258 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6e8d0ae17e2b48b18bdbe21ecf6345fa: stopping tablet replica
I20260812 06:18:28.423071 19258 master.cc:584] Master@127.18.206.190:46121 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4922 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9782 ms total)

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